--check-destination-dir taking a very long time

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
25 messages Options
12
Reply | Threaded
Open this post in threaded view
|

--check-destination-dir taking a very long time

Walt Mankowski
I've been running rdiff-backup to an external USB drive for years
without any problems. Over the weekend my backup failed with

  Exception '[Errno 28] No space left on device

This is odd, since there is 1.2 TB free on the drive. I didn't see any
errors in syslog, and I was able to create a new file on the drive
without any problem.

Thinking it might have been a USB glitch I rebooted the machine and
now I'm running

  rdiff-backup --check-destination-dir

to recover the backup directory. It was taking a very long time, and I
restarted it with the -v8 hoping I might get some clue as to what it
was doing. Unfortunately after spitting out some routine-looking
output in the first few seconds it's now been running in silence for
nearly 12 hours.

It's getting CPU time and I don't see any errors in syslog, so I'm
assuming that it's doing something. But I don't have any idea what
it's doing, if it's working correctly, or how much longer it's likely
to take.

Is it normal that a regression takes this long? /backup is currently
at 527 GB.

Thanks.

Walt

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Patrik Dufresne
Hello Walt, could you double check the disk space. Especially the number of
inode ? It's probably the root cause of your issue.

On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <[hidden email]> wrote:

> I've been running rdiff-backup to an external USB drive for years
> without any problems. Over the weekend my backup failed with
>
>   Exception '[Errno 28] No space left on device
>
> This is odd, since there is 1.2 TB free on the drive. I didn't see any
> errors in syslog, and I was able to create a new file on the drive
> without any problem.
>
> Thinking it might have been a USB glitch I rebooted the machine and
> now I'm running
>
>   rdiff-backup --check-destination-dir
>
> to recover the backup directory. It was taking a very long time, and I
> restarted it with the -v8 hoping I might get some clue as to what it
> was doing. Unfortunately after spitting out some routine-looking
> output in the first few seconds it's now been running in silence for
> nearly 12 hours.
>
> It's getting CPU time and I don't see any errors in syslog, so I'm
> assuming that it's doing something. But I don't have any idea what
> it's doing, if it's working correctly, or how much longer it's likely
> to take.
>
> Is it normal that a regression takes this long? /backup is currently
> at 527 GB.
>
> Thanks.
>
> Walt
>
> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL:
> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Walt Mankowski
Good idea! But unfortunately it doesn't seem to be the problem:

% df -hi /backup
Filesystem     Inodes IUsed IFree IUse% Mounted on
/dev/sde1        117M   19M   98M   17% /backup


On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:

> Hello Walt, could you double check the disk space. Especially the number of
> inode ? It's probably the root cause of your issue.
>
> On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <[hidden email]> wrote:
>
> > I've been running rdiff-backup to an external USB drive for years
> > without any problems. Over the weekend my backup failed with
> >
> >   Exception '[Errno 28] No space left on device
> >
> > This is odd, since there is 1.2 TB free on the drive. I didn't see any
> > errors in syslog, and I was able to create a new file on the drive
> > without any problem.
> >
> > Thinking it might have been a USB glitch I rebooted the machine and
> > now I'm running
> >
> >   rdiff-backup --check-destination-dir
> >
> > to recover the backup directory. It was taking a very long time, and I
> > restarted it with the -v8 hoping I might get some clue as to what it
> > was doing. Unfortunately after spitting out some routine-looking
> > output in the first few seconds it's now been running in silence for
> > nearly 12 hours.
> >
> > It's getting CPU time and I don't see any errors in syslog, so I'm
> > assuming that it's doing something. But I don't have any idea what
> > it's doing, if it's working correctly, or how much longer it's likely
> > to take.
> >
> > Is it normal that a regression takes this long? /backup is currently
> > at 527 GB.
> >
> > Thanks.
> >
> > Walt
> >
> > _______________________________________________
> > rdiff-backup-users mailing list at [hidden email]
> > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > Wiki URL:
> > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Patrik Dufresne
Hum, this is strange. It should not fail with a "no space left on device".
Could you provide the log generate with -v9 ? Plz provide the full command
line you used.

What is the filesystem of your USB drive ?


If you try to run the backup again do you have an error?


On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]> wrote:

> Good idea! But unfortunately it doesn't seem to be the problem:
>
> % df -hi /backup
> Filesystem     Inodes IUsed IFree IUse% Mounted on
> /dev/sde1        117M   19M   98M   17% /backup
>
>
> On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
> > Hello Walt, could you double check the disk space. Especially the number
> of
> > inode ? It's probably the root cause of your issue.
> >
> > On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <[hidden email]> wrote:
> >
> > > I've been running rdiff-backup to an external USB drive for years
> > > without any problems. Over the weekend my backup failed with
> > >
> > >   Exception '[Errno 28] No space left on device
> > >
> > > This is odd, since there is 1.2 TB free on the drive. I didn't see any
> > > errors in syslog, and I was able to create a new file on the drive
> > > without any problem.
> > >
> > > Thinking it might have been a USB glitch I rebooted the machine and
> > > now I'm running
> > >
> > >   rdiff-backup --check-destination-dir
> > >
> > > to recover the backup directory. It was taking a very long time, and I
> > > restarted it with the -v8 hoping I might get some clue as to what it
> > > was doing. Unfortunately after spitting out some routine-looking
> > > output in the first few seconds it's now been running in silence for
> > > nearly 12 hours.
> > >
> > > It's getting CPU time and I don't see any errors in syslog, so I'm
> > > assuming that it's doing something. But I don't have any idea what
> > > it's doing, if it's working correctly, or how much longer it's likely
> > > to take.
> > >
> > > Is it normal that a regression takes this long? /backup is currently
> > > at 527 GB.
> > >
> > > Thanks.
> > >
> > > Walt
> > >
> > > _______________________________________________
> > > rdiff-backup-users mailing list at [hidden email]
> > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > Wiki URL:
> > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>
> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL:
> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Walt Mankowski
On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
> Hum, this is strange. It should not fail with a "no space left on device".

Agreed! That's why I originally thought it must have been some sort of
USB glitch.

> Could you provide the log generate with -v9 ? Plz provide the full command
> line you used.

So kill the run with -v8?

> What is the filesystem of your USB drive ?

ext4

> If you try to run the backup again do you have an error?

In fact that happened last night. My normal nightly backup kicked in
while a previous attempt at running --check-destination-dir was still
running. The cronjob reported:

  Previous backup seems to have failed, regressing destination now.
  Fatal Error: Killed with signal 15

The latter was when I killed it when I woke up and saw that both of
them were running.

Walt

> On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]> wrote:
>
> > Good idea! But unfortunately it doesn't seem to be the problem:
> >
> > % df -hi /backup
> > Filesystem     Inodes IUsed IFree IUse% Mounted on
> > /dev/sde1        117M   19M   98M   17% /backup
> >
> >
> > On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
> > > Hello Walt, could you double check the disk space. Especially the number
> > of
> > > inode ? It's probably the root cause of your issue.
> > >
> > > On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <[hidden email]> wrote:
> > >
> > > > I've been running rdiff-backup to an external USB drive for years
> > > > without any problems. Over the weekend my backup failed with
> > > >
> > > >   Exception '[Errno 28] No space left on device
> > > >
> > > > This is odd, since there is 1.2 TB free on the drive. I didn't see any
> > > > errors in syslog, and I was able to create a new file on the drive
> > > > without any problem.
> > > >
> > > > Thinking it might have been a USB glitch I rebooted the machine and
> > > > now I'm running
> > > >
> > > >   rdiff-backup --check-destination-dir
> > > >
> > > > to recover the backup directory. It was taking a very long time, and I
> > > > restarted it with the -v8 hoping I might get some clue as to what it
> > > > was doing. Unfortunately after spitting out some routine-looking
> > > > output in the first few seconds it's now been running in silence for
> > > > nearly 12 hours.
> > > >
> > > > It's getting CPU time and I don't see any errors in syslog, so I'm
> > > > assuming that it's doing something. But I don't have any idea what
> > > > it's doing, if it's working correctly, or how much longer it's likely
> > > > to take.
> > > >
> > > > Is it normal that a regression takes this long? /backup is currently
> > > > at 527 GB.
> > > >
> > > > Thanks.
> > > >
> > > > Walt
> > > >
> > > > _______________________________________________
> > > > rdiff-backup-users mailing list at [hidden email]
> > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > Wiki URL:
> > > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> >
> > _______________________________________________
> > rdiff-backup-users mailing list at [hidden email]
> > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > Wiki URL:
> > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Patrik Dufresne-2
At this point, I would just kill all the rdiff-backup process. Then
manually start the backup again to the USB drive. Run it with -v9 and post
the logs here.

That should provide us enough guidance about what is going on. Either the
process will fail quickly (this is what I expect). If the process is taking
too long, try to give us the logs that you gather.

Since it's USB, could you check if the USB speed is alright ? If for
whatever reason the USB speed switched from USB 3.0 to USB 2.0. It might
take for ever to do a backup. You could double check this with "lsusb -t".
Expect 5000M for USB 3

ikus060@ikus060-laptop:~/workspace/HPUCA/hpuca-valuepack.git$ lsusb -t
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 10000M
    |__ Port 4: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
    |__ Port 5: Dev 14, If 0, Class=Hub, Driver=hub/3p, 480M

A look to "dmesg" might also reveal some information about a change to the
usb channel.

--
Patrik Dufresne Service Logiciel inc.
http://www.patrikdufresne.com <http://patrikdufresne.com/>/
514-971-6442
130 rue Doris
St-Colomban, QC J5K 1T9


On Mon, Sep 9, 2019 at 7:47 PM Walt Mankowski <[hidden email]> wrote:

> On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
> > Hum, this is strange. It should not fail with a "no space left on
> device".
>
> Agreed! That's why I originally thought it must have been some sort of
> USB glitch.
>
> > Could you provide the log generate with -v9 ? Plz provide the full
> command
> > line you used.
>
> So kill the run with -v8?
>
> > What is the filesystem of your USB drive ?
>
> ext4
>
> > If you try to run the backup again do you have an error?
>
> In fact that happened last night. My normal nightly backup kicked in
> while a previous attempt at running --check-destination-dir was still
> running. The cronjob reported:
>
>   Previous backup seems to have failed, regressing destination now.
>   Fatal Error: Killed with signal 15
>
> The latter was when I killed it when I woke up and saw that both of
> them were running.
>
> Walt
>
> > On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]> wrote:
> >
> > > Good idea! But unfortunately it doesn't seem to be the problem:
> > >
> > > % df -hi /backup
> > > Filesystem     Inodes IUsed IFree IUse% Mounted on
> > > /dev/sde1        117M   19M   98M   17% /backup
> > >
> > >
> > > On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
> > > > Hello Walt, could you double check the disk space. Especially the
> number
> > > of
> > > > inode ? It's probably the root cause of your issue.
> > > >
> > > > On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <[hidden email]>
> wrote:
> > > >
> > > > > I've been running rdiff-backup to an external USB drive for years
> > > > > without any problems. Over the weekend my backup failed with
> > > > >
> > > > >   Exception '[Errno 28] No space left on device
> > > > >
> > > > > This is odd, since there is 1.2 TB free on the drive. I didn't see
> any
> > > > > errors in syslog, and I was able to create a new file on the drive
> > > > > without any problem.
> > > > >
> > > > > Thinking it might have been a USB glitch I rebooted the machine and
> > > > > now I'm running
> > > > >
> > > > >   rdiff-backup --check-destination-dir
> > > > >
> > > > > to recover the backup directory. It was taking a very long time,
> and I
> > > > > restarted it with the -v8 hoping I might get some clue as to what
> it
> > > > > was doing. Unfortunately after spitting out some routine-looking
> > > > > output in the first few seconds it's now been running in silence
> for
> > > > > nearly 12 hours.
> > > > >
> > > > > It's getting CPU time and I don't see any errors in syslog, so I'm
> > > > > assuming that it's doing something. But I don't have any idea what
> > > > > it's doing, if it's working correctly, or how much longer it's
> likely
> > > > > to take.
> > > > >
> > > > > Is it normal that a regression takes this long? /backup is
> currently
> > > > > at 527 GB.
> > > > >
> > > > > Thanks.
> > > > >
> > > > > Walt
> > > > >
> > > > > _______________________________________________
> > > > > rdiff-backup-users mailing list at [hidden email]
> > > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > > Wiki URL:
> > > > >
> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> > >
> > > _______________________________________________
> > > rdiff-backup-users mailing list at [hidden email]
> > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > Wiki URL:
> > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>
> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL:
> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Walt Mankowski
I ran

  $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup.txt

This time it exited right away. I've attached the log file, where the
key message is

  Fatal Error: It appears that a previous rdiff-backup session with
  process id 4351 is still running.

Process 4351 is /lib/systemd/systemd-resolved

Is it safe to rerun it with --force?

Walt

On Mon, Sep 09, 2019 at 08:04:46PM -0400, Patrik Dufresne wrote:

> At this point, I would just kill all the rdiff-backup process. Then
> manually start the backup again to the USB drive. Run it with -v9 and post
> the logs here.
>
> That should provide us enough guidance about what is going on. Either the
> process will fail quickly (this is what I expect). If the process is taking
> too long, try to give us the logs that you gather.
>
> Since it's USB, could you check if the USB speed is alright ? If for
> whatever reason the USB speed switched from USB 3.0 to USB 2.0. It might
> take for ever to do a backup. You could double check this with "lsusb -t".
> Expect 5000M for USB 3
>
> ikus060@ikus060-laptop:~/workspace/HPUCA/hpuca-valuepack.git$ lsusb -t
> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 10000M
>     |__ Port 4: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage, 5000M
> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
>     |__ Port 5: Dev 14, If 0, Class=Hub, Driver=hub/3p, 480M
>
> A look to "dmesg" might also reveal some information about a change to the
> usb channel.
>
> --
> Patrik Dufresne Service Logiciel inc.
> http://www.patrikdufresne.com <http://patrikdufresne.com/>/
> 514-971-6442
> 130 rue Doris
> St-Colomban, QC J5K 1T9
>
>
> On Mon, Sep 9, 2019 at 7:47 PM Walt Mankowski <[hidden email]> wrote:
>
> > On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
> > > Hum, this is strange. It should not fail with a "no space left on
> > device".
> >
> > Agreed! That's why I originally thought it must have been some sort of
> > USB glitch.
> >
> > > Could you provide the log generate with -v9 ? Plz provide the full
> > command
> > > line you used.
> >
> > So kill the run with -v8?
> >
> > > What is the filesystem of your USB drive ?
> >
> > ext4
> >
> > > If you try to run the backup again do you have an error?
> >
> > In fact that happened last night. My normal nightly backup kicked in
> > while a previous attempt at running --check-destination-dir was still
> > running. The cronjob reported:
> >
> >   Previous backup seems to have failed, regressing destination now.
> >   Fatal Error: Killed with signal 15
> >
> > The latter was when I killed it when I woke up and saw that both of
> > them were running.
> >
> > Walt
> >
> > > On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]> wrote:
> > >
> > > > Good idea! But unfortunately it doesn't seem to be the problem:
> > > >
> > > > % df -hi /backup
> > > > Filesystem     Inodes IUsed IFree IUse% Mounted on
> > > > /dev/sde1        117M   19M   98M   17% /backup
> > > >
> > > >
> > > > On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
> > > > > Hello Walt, could you double check the disk space. Especially the
> > number
> > > > of
> > > > > inode ? It's probably the root cause of your issue.
> > > > >
> > > > > On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <[hidden email]>
> > wrote:
> > > > >
> > > > > > I've been running rdiff-backup to an external USB drive for years
> > > > > > without any problems. Over the weekend my backup failed with
> > > > > >
> > > > > >   Exception '[Errno 28] No space left on device
> > > > > >
> > > > > > This is odd, since there is 1.2 TB free on the drive. I didn't see
> > any
> > > > > > errors in syslog, and I was able to create a new file on the drive
> > > > > > without any problem.
> > > > > >
> > > > > > Thinking it might have been a USB glitch I rebooted the machine and
> > > > > > now I'm running
> > > > > >
> > > > > >   rdiff-backup --check-destination-dir
> > > > > >
> > > > > > to recover the backup directory. It was taking a very long time,
> > and I
> > > > > > restarted it with the -v8 hoping I might get some clue as to what
> > it
> > > > > > was doing. Unfortunately after spitting out some routine-looking
> > > > > > output in the first few seconds it's now been running in silence
> > for
> > > > > > nearly 12 hours.
> > > > > >
> > > > > > It's getting CPU time and I don't see any errors in syslog, so I'm
> > > > > > assuming that it's doing something. But I don't have any idea what
> > > > > > it's doing, if it's working correctly, or how much longer it's
> > likely
> > > > > > to take.
> > > > > >
> > > > > > Is it normal that a regression takes this long? /backup is
> > currently
> > > > > > at 527 GB.
> > > > > >
> > > > > > Thanks.
> > > > > >
> > > > > > Walt
> > > > > >
> > > > > > _______________________________________________
> > > > > > rdiff-backup-users mailing list at [hidden email]
> > > > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > > > Wiki URL:
> > > > > >
> > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> > > >
> > > > _______________________________________________
> > > > rdiff-backup-users mailing list at [hidden email]
> > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > Wiki URL:
> > > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> >
> > _______________________________________________
> > rdiff-backup-users mailing list at [hidden email]
> > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > Wiki URL:
> > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki

rdiff-backup.txt (5K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Walt Mankowski
I found a file named

  rdiff-backup-data/current_mirror.2019-09-08T03:01:02-04:00.data

which contained

  4351

I moved it out of the way and reran the backup command. This time it
through an exception. The output is in the attached log file.

Walt

On Mon, Sep 09, 2019 at 08:17:04PM -0400, Walt Mankowski wrote:

> I ran
>
>   $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup.txt
>
> This time it exited right away. I've attached the log file, where the
> key message is
>
>   Fatal Error: It appears that a previous rdiff-backup session with
>   process id 4351 is still running.
>
> Process 4351 is /lib/systemd/systemd-resolved
>
> Is it safe to rerun it with --force?
>
> Walt
>
> On Mon, Sep 09, 2019 at 08:04:46PM -0400, Patrik Dufresne wrote:
> > At this point, I would just kill all the rdiff-backup process. Then
> > manually start the backup again to the USB drive. Run it with -v9 and post
> > the logs here.
> >
> > That should provide us enough guidance about what is going on. Either the
> > process will fail quickly (this is what I expect). If the process is taking
> > too long, try to give us the logs that you gather.
> >
> > Since it's USB, could you check if the USB speed is alright ? If for
> > whatever reason the USB speed switched from USB 3.0 to USB 2.0. It might
> > take for ever to do a backup. You could double check this with "lsusb -t".
> > Expect 5000M for USB 3
> >
> > ikus060@ikus060-laptop:~/workspace/HPUCA/hpuca-valuepack.git$ lsusb -t
> > /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 10000M
> >     |__ Port 4: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage, 5000M
> > /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
> >     |__ Port 5: Dev 14, If 0, Class=Hub, Driver=hub/3p, 480M
> >
> > A look to "dmesg" might also reveal some information about a change to the
> > usb channel.
> >
> > --
> > Patrik Dufresne Service Logiciel inc.
> > http://www.patrikdufresne.com <http://patrikdufresne.com/>/
> > 514-971-6442
> > 130 rue Doris
> > St-Colomban, QC J5K 1T9
> >
> >
> > On Mon, Sep 9, 2019 at 7:47 PM Walt Mankowski <[hidden email]> wrote:
> >
> > > On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
> > > > Hum, this is strange. It should not fail with a "no space left on
> > > device".
> > >
> > > Agreed! That's why I originally thought it must have been some sort of
> > > USB glitch.
> > >
> > > > Could you provide the log generate with -v9 ? Plz provide the full
> > > command
> > > > line you used.
> > >
> > > So kill the run with -v8?
> > >
> > > > What is the filesystem of your USB drive ?
> > >
> > > ext4
> > >
> > > > If you try to run the backup again do you have an error?
> > >
> > > In fact that happened last night. My normal nightly backup kicked in
> > > while a previous attempt at running --check-destination-dir was still
> > > running. The cronjob reported:
> > >
> > >   Previous backup seems to have failed, regressing destination now.
> > >   Fatal Error: Killed with signal 15
> > >
> > > The latter was when I killed it when I woke up and saw that both of
> > > them were running.
> > >
> > > Walt
> > >
> > > > On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]> wrote:
> > > >
> > > > > Good idea! But unfortunately it doesn't seem to be the problem:
> > > > >
> > > > > % df -hi /backup
> > > > > Filesystem     Inodes IUsed IFree IUse% Mounted on
> > > > > /dev/sde1        117M   19M   98M   17% /backup
> > > > >
> > > > >
> > > > > On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
> > > > > > Hello Walt, could you double check the disk space. Especially the
> > > number
> > > > > of
> > > > > > inode ? It's probably the root cause of your issue.
> > > > > >
> > > > > > On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <[hidden email]>
> > > wrote:
> > > > > >
> > > > > > > I've been running rdiff-backup to an external USB drive for years
> > > > > > > without any problems. Over the weekend my backup failed with
> > > > > > >
> > > > > > >   Exception '[Errno 28] No space left on device
> > > > > > >
> > > > > > > This is odd, since there is 1.2 TB free on the drive. I didn't see
> > > any
> > > > > > > errors in syslog, and I was able to create a new file on the drive
> > > > > > > without any problem.
> > > > > > >
> > > > > > > Thinking it might have been a USB glitch I rebooted the machine and
> > > > > > > now I'm running
> > > > > > >
> > > > > > >   rdiff-backup --check-destination-dir
> > > > > > >
> > > > > > > to recover the backup directory. It was taking a very long time,
> > > and I
> > > > > > > restarted it with the -v8 hoping I might get some clue as to what
> > > it
> > > > > > > was doing. Unfortunately after spitting out some routine-looking
> > > > > > > output in the first few seconds it's now been running in silence
> > > for
> > > > > > > nearly 12 hours.
> > > > > > >
> > > > > > > It's getting CPU time and I don't see any errors in syslog, so I'm
> > > > > > > assuming that it's doing something. But I don't have any idea what
> > > > > > > it's doing, if it's working correctly, or how much longer it's
> > > likely
> > > > > > > to take.
> > > > > > >
> > > > > > > Is it normal that a regression takes this long? /backup is
> > > currently
> > > > > > > at 527 GB.
> > > > > > >
> > > > > > > Thanks.
> > > > > > >
> > > > > > > Walt
> > > > > > >
> > > > > > > _______________________________________________
> > > > > > > rdiff-backup-users mailing list at [hidden email]
> > > > > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > > > > Wiki URL:
> > > > > > >
> > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> > > > >
> > > > > _______________________________________________
> > > > > rdiff-backup-users mailing list at [hidden email]
> > > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > > Wiki URL:
> > > > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> > >
> > > _______________________________________________
> > > rdiff-backup-users mailing list at [hidden email]
> > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > Wiki URL:
> > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki

> Mon Sep  9 20:09:56 2019  Using rdiff-backup version 1.2.8
> Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows ACLs
> not supported by filesystem at /
> Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem at /
> Mon Sep  9 20:09:57 2019  -----------------------------------------------------------------
> Detected abilities for source (read only) file system:
>   Access control lists                         On
>   Extended attributes                          On
>   Windows access control lists                 Off
>   Case sensitivity                             On
>   Escape DOS devices                           Off
>   Escape trailing spaces                       Off
>   Mac OS X style resource forks                Off
>   Mac OS X Finder information                  Off
> -----------------------------------------------------------------
> Mon Sep  9 20:09:57 2019  Making directory /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
> Mon Sep  9 20:09:57 2019  Making directory /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
> Mon Sep  9 20:09:57 2019  Hard linking /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl/hardlinked_file2 to /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
> Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows ACLs
> not supported by filesystem at /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file2
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
> Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem at /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> Mon Sep  9 20:09:57 2019  Removing directory /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> Mon Sep  9 20:09:57 2019  -----------------------------------------------------------------
> Detected abilities for destination (read/write) file system:
>   Ownership changing                         Mon Sep  9 20:09:57 2019  Fatal Error: It appears that a previous rdiff-backup session with process
> id 4351 is still running.  If two different rdiff-backup processes write
> the same repository simultaneously, data corruption will probably
> result.  To proceed with regress anyway, rerun rdiff-backup with the
> --force option.
>   On
>   Hard linking                                 On
>   fsync() directories                          On
>   Directory inc permissions                    On
>   High-bit permissions                         On
>   Symlink permissions                          Off
>   Extended filenames                           On
>   Windows reserved filenames                   Off
>   Access control lists                         On
>   Extended attributes                          On
>   Windows access control lists                 Off
>   Case sensitivity                             On
>   Escape DOS devices                           Off
>   Escape trailing spaces                       Off
>   Mac OS X style resource forks                Off
>   Mac OS X Finder information                  Off
> -----------------------------------------------------------------
> Mon Sep  9 20:09:57 2019  Backup: must_escape_dos_devices = 0

> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki


_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki

rdiff-backup2.txt (10K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Dominic Raferd-3
Is it possible you are running out of temporary file space? You can specify
a different tmp location with switch --tempdir (or, if running to remote
server, --remote-tempdir). When checking an archive rdiff-backup may need a
lot of temporary space for all that unpacking. By the way, it may not be
apparent that the temporary file location is being used (or running out of
space) as the temporary files that rdiff-backup creates are not visible
there (there is some technical reason for this that I don't understand).

On Tue, 10 Sep 2019 at 04:53, Walt Mankowski <[hidden email]> wrote:

> I found a file named
>
>   rdiff-backup-data/current_mirror.2019-09-08T03:01:02-04:00.data
>
> which contained
>
>   4351
>
> I moved it out of the way and reran the backup command. This time it
> through an exception. The output is in the attached log file.
>
> Walt
>
> On Mon, Sep 09, 2019 at 08:17:04PM -0400, Walt Mankowski wrote:
> > I ran
> >
> >   $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist
> /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup.txt
> >
> > This time it exited right away. I've attached the log file, where the
> > key message is
> >
> >   Fatal Error: It appears that a previous rdiff-backup session with
> >   process id 4351 is still running.
> >
> > Process 4351 is /lib/systemd/systemd-resolved
> >
> > Is it safe to rerun it with --force?
> >
> > Walt
> >
> > On Mon, Sep 09, 2019 at 08:04:46PM -0400, Patrik Dufresne wrote:
> > > At this point, I would just kill all the rdiff-backup process. Then
> > > manually start the backup again to the USB drive. Run it with -v9 and
> post
> > > the logs here.
> > >
> > > That should provide us enough guidance about what is going on. Either
> the
> > > process will fail quickly (this is what I expect). If the process is
> taking
> > > too long, try to give us the logs that you gather.
> > >
> > > Since it's USB, could you check if the USB speed is alright ? If for
> > > whatever reason the USB speed switched from USB 3.0 to USB 2.0. It
> might
> > > take for ever to do a backup. You could double check this with "lsusb
> -t".
> > > Expect 5000M for USB 3
> > >
> > > ikus060@ikus060-laptop:~/workspace/HPUCA/hpuca-valuepack.git$ lsusb -t
> > > /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 10000M
> > >     |__ Port 4: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage,
> 5000M
> > > /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
> > >     |__ Port 5: Dev 14, If 0, Class=Hub, Driver=hub/3p, 480M
> > >
> > > A look to "dmesg" might also reveal some information about a change to
> the
> > > usb channel.
> > >
> > > --
> > > Patrik Dufresne Service Logiciel inc.
> > > http://www.patrikdufresne.com <http://patrikdufresne.com/>/
> > > 514-971-6442
> > > 130 rue Doris
> > > St-Colomban, QC J5K 1T9
> > >
> > >
> > > On Mon, Sep 9, 2019 at 7:47 PM Walt Mankowski <[hidden email]>
> wrote:
> > >
> > > > On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
> > > > > Hum, this is strange. It should not fail with a "no space left on
> > > > device".
> > > >
> > > > Agreed! That's why I originally thought it must have been some sort
> of
> > > > USB glitch.
> > > >
> > > > > Could you provide the log generate with -v9 ? Plz provide the full
> > > > command
> > > > > line you used.
> > > >
> > > > So kill the run with -v8?
> > > >
> > > > > What is the filesystem of your USB drive ?
> > > >
> > > > ext4
> > > >
> > > > > If you try to run the backup again do you have an error?
> > > >
> > > > In fact that happened last night. My normal nightly backup kicked in
> > > > while a previous attempt at running --check-destination-dir was still
> > > > running. The cronjob reported:
> > > >
> > > >   Previous backup seems to have failed, regressing destination now.
> > > >   Fatal Error: Killed with signal 15
> > > >
> > > > The latter was when I killed it when I woke up and saw that both of
> > > > them were running.
> > > >
> > > > Walt
> > > >
> > > > > On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]>
> wrote:
> > > > >
> > > > > > Good idea! But unfortunately it doesn't seem to be the problem:
> > > > > >
> > > > > > % df -hi /backup
> > > > > > Filesystem     Inodes IUsed IFree IUse% Mounted on
> > > > > > /dev/sde1        117M   19M   98M   17% /backup
> > > > > >
> > > > > >
> > > > > > On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
> > > > > > > Hello Walt, could you double check the disk space. Especially
> the
> > > > number
> > > > > > of
> > > > > > > inode ? It's probably the root cause of your issue.
> > > > > > >
> > > > > > > On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <
> [hidden email]>
> > > > wrote:
> > > > > > >
> > > > > > > > I've been running rdiff-backup to an external USB drive for
> years
> > > > > > > > without any problems. Over the weekend my backup failed with
> > > > > > > >
> > > > > > > >   Exception '[Errno 28] No space left on device
> > > > > > > >
> > > > > > > > This is odd, since there is 1.2 TB free on the drive. I
> didn't see
> > > > any
> > > > > > > > errors in syslog, and I was able to create a new file on the
> drive
> > > > > > > > without any problem.
> > > > > > > >
> > > > > > > > Thinking it might have been a USB glitch I rebooted the
> machine and
> > > > > > > > now I'm running
> > > > > > > >
> > > > > > > >   rdiff-backup --check-destination-dir
> > > > > > > >
> > > > > > > > to recover the backup directory. It was taking a very long
> time,
> > > > and I
> > > > > > > > restarted it with the -v8 hoping I might get some clue as to
> what
> > > > it
> > > > > > > > was doing. Unfortunately after spitting out some
> routine-looking
> > > > > > > > output in the first few seconds it's now been running in
> silence
> > > > for
> > > > > > > > nearly 12 hours.
> > > > > > > >
> > > > > > > > It's getting CPU time and I don't see any errors in syslog,
> so I'm
> > > > > > > > assuming that it's doing something. But I don't have any
> idea what
> > > > > > > > it's doing, if it's working correctly, or how much longer
> it's
> > > > likely
> > > > > > > > to take.
> > > > > > > >
> > > > > > > > Is it normal that a regression takes this long? /backup is
> > > > currently
> > > > > > > > at 527 GB.
> > > > > > > >
> > > > > > > > Thanks.
> > > > > > > >
> > > > > > > > Walt
> > > > > > > >
> > > > > > > > _______________________________________________
> > > > > > > > rdiff-backup-users mailing list at
> [hidden email]
> > > > > > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > > > > > Wiki URL:
> > > > > > > >
> > > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> > > > > >
> > > > > > _______________________________________________
> > > > > > rdiff-backup-users mailing list at [hidden email]
> > > > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > > > Wiki URL:
> > > > > >
> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> > > >
> > > > _______________________________________________
> > > > rdiff-backup-users mailing list at [hidden email]
> > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > Wiki URL:
> > > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>
> > Mon Sep  9 20:09:56 2019  Using rdiff-backup version 1.2.8
> > Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows
> ACLs
> > not supported by filesystem at /
> > Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem
> at /
> > Mon Sep  9 20:09:57 2019
> -----------------------------------------------------------------
> > Detected abilities for source (read only) file system:
> >   Access control lists                         On
> >   Extended attributes                          On
> >   Windows access control lists                 Off
> >   Case sensitivity                             On
> >   Escape DOS devices                           Off
> >   Escape trailing spaces                       Off
> >   Mac OS X style resource forks                Off
> >   Mac OS X Finder information                  Off
> > -----------------------------------------------------------------
> > Mon Sep  9 20:09:57 2019  Making directory
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
> > Mon Sep  9 20:09:57 2019  Making directory
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
> > Mon Sep  9 20:09:57 2019  Hard linking
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl/hardlinked_file2 to
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
> > Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows
> ACLs
> > not supported by filesystem at
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
> > Mon Sep  9 20:09:57 2019  Touching
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file2
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
> > Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem
> at /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > Mon Sep  9 20:09:57 2019  Deleting
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > Mon Sep  9 20:09:57 2019  Removing directory
> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > Mon Sep  9 20:09:57 2019
> -----------------------------------------------------------------
> > Detected abilities for destination (read/write) file system:
> >   Ownership changing                         Mon Sep  9 20:09:57 2019
> Fatal Error: It appears that a previous rdiff-backup session with process
> > id 4351 is still running.  If two different rdiff-backup processes write
> > the same repository simultaneously, data corruption will probably
> > result.  To proceed with regress anyway, rerun rdiff-backup with the
> > --force option.
> >   On
> >   Hard linking                                 On
> >   fsync() directories                          On
> >   Directory inc permissions                    On
> >   High-bit permissions                         On
> >   Symlink permissions                          Off
> >   Extended filenames                           On
> >   Windows reserved filenames                   Off
> >   Access control lists                         On
> >   Extended attributes                          On
> >   Windows access control lists                 Off
> >   Case sensitivity                             On
> >   Escape DOS devices                           Off
> >   Escape trailing spaces                       Off
> >   Mac OS X style resource forks                Off
> >   Mac OS X Finder information                  Off
> > -----------------------------------------------------------------
> > Mon Sep  9 20:09:57 2019  Backup: must_escape_dos_devices = 0
>
> > _______________________________________________
> > rdiff-backup-users mailing list at [hidden email]
> > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > Wiki URL:
> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>
> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL:
> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Walt Mankowski
It's not likely. That partition has 14 GB free.

On Tue, Sep 10, 2019 at 07:52:38AM +0300, Dominic Raferd wrote:

> Is it possible you are running out of temporary file space? You can specify
> a different tmp location with switch --tempdir (or, if running to remote
> server, --remote-tempdir). When checking an archive rdiff-backup may need a
> lot of temporary space for all that unpacking. By the way, it may not be
> apparent that the temporary file location is being used (or running out of
> space) as the temporary files that rdiff-backup creates are not visible
> there (there is some technical reason for this that I don't understand).
>
> On Tue, 10 Sep 2019 at 04:53, Walt Mankowski <[hidden email]> wrote:
>
> > I found a file named
> >
> >   rdiff-backup-data/current_mirror.2019-09-08T03:01:02-04:00.data
> >
> > which contained
> >
> >   4351
> >
> > I moved it out of the way and reran the backup command. This time it
> > through an exception. The output is in the attached log file.
> >
> > Walt
> >
> > On Mon, Sep 09, 2019 at 08:17:04PM -0400, Walt Mankowski wrote:
> > > I ran
> > >
> > >   $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist
> > /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup.txt
> > >
> > > This time it exited right away. I've attached the log file, where the
> > > key message is
> > >
> > >   Fatal Error: It appears that a previous rdiff-backup session with
> > >   process id 4351 is still running.
> > >
> > > Process 4351 is /lib/systemd/systemd-resolved
> > >
> > > Is it safe to rerun it with --force?
> > >
> > > Walt
> > >
> > > On Mon, Sep 09, 2019 at 08:04:46PM -0400, Patrik Dufresne wrote:
> > > > At this point, I would just kill all the rdiff-backup process. Then
> > > > manually start the backup again to the USB drive. Run it with -v9 and
> > post
> > > > the logs here.
> > > >
> > > > That should provide us enough guidance about what is going on. Either
> > the
> > > > process will fail quickly (this is what I expect). If the process is
> > taking
> > > > too long, try to give us the logs that you gather.
> > > >
> > > > Since it's USB, could you check if the USB speed is alright ? If for
> > > > whatever reason the USB speed switched from USB 3.0 to USB 2.0. It
> > might
> > > > take for ever to do a backup. You could double check this with "lsusb
> > -t".
> > > > Expect 5000M for USB 3
> > > >
> > > > ikus060@ikus060-laptop:~/workspace/HPUCA/hpuca-valuepack.git$ lsusb -t
> > > > /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 10000M
> > > >     |__ Port 4: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage,
> > 5000M
> > > > /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
> > > >     |__ Port 5: Dev 14, If 0, Class=Hub, Driver=hub/3p, 480M
> > > >
> > > > A look to "dmesg" might also reveal some information about a change to
> > the
> > > > usb channel.
> > > >
> > > > --
> > > > Patrik Dufresne Service Logiciel inc.
> > > > http://www.patrikdufresne.com <http://patrikdufresne.com/>/
> > > > 514-971-6442
> > > > 130 rue Doris
> > > > St-Colomban, QC J5K 1T9
> > > >
> > > >
> > > > On Mon, Sep 9, 2019 at 7:47 PM Walt Mankowski <[hidden email]>
> > wrote:
> > > >
> > > > > On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
> > > > > > Hum, this is strange. It should not fail with a "no space left on
> > > > > device".
> > > > >
> > > > > Agreed! That's why I originally thought it must have been some sort
> > of
> > > > > USB glitch.
> > > > >
> > > > > > Could you provide the log generate with -v9 ? Plz provide the full
> > > > > command
> > > > > > line you used.
> > > > >
> > > > > So kill the run with -v8?
> > > > >
> > > > > > What is the filesystem of your USB drive ?
> > > > >
> > > > > ext4
> > > > >
> > > > > > If you try to run the backup again do you have an error?
> > > > >
> > > > > In fact that happened last night. My normal nightly backup kicked in
> > > > > while a previous attempt at running --check-destination-dir was still
> > > > > running. The cronjob reported:
> > > > >
> > > > >   Previous backup seems to have failed, regressing destination now.
> > > > >   Fatal Error: Killed with signal 15
> > > > >
> > > > > The latter was when I killed it when I woke up and saw that both of
> > > > > them were running.
> > > > >
> > > > > Walt
> > > > >
> > > > > > On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]>
> > wrote:
> > > > > >
> > > > > > > Good idea! But unfortunately it doesn't seem to be the problem:
> > > > > > >
> > > > > > > % df -hi /backup
> > > > > > > Filesystem     Inodes IUsed IFree IUse% Mounted on
> > > > > > > /dev/sde1        117M   19M   98M   17% /backup
> > > > > > >
> > > > > > >
> > > > > > > On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
> > > > > > > > Hello Walt, could you double check the disk space. Especially
> > the
> > > > > number
> > > > > > > of
> > > > > > > > inode ? It's probably the root cause of your issue.
> > > > > > > >
> > > > > > > > On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <
> > [hidden email]>
> > > > > wrote:
> > > > > > > >
> > > > > > > > > I've been running rdiff-backup to an external USB drive for
> > years
> > > > > > > > > without any problems. Over the weekend my backup failed with
> > > > > > > > >
> > > > > > > > >   Exception '[Errno 28] No space left on device
> > > > > > > > >
> > > > > > > > > This is odd, since there is 1.2 TB free on the drive. I
> > didn't see
> > > > > any
> > > > > > > > > errors in syslog, and I was able to create a new file on the
> > drive
> > > > > > > > > without any problem.
> > > > > > > > >
> > > > > > > > > Thinking it might have been a USB glitch I rebooted the
> > machine and
> > > > > > > > > now I'm running
> > > > > > > > >
> > > > > > > > >   rdiff-backup --check-destination-dir
> > > > > > > > >
> > > > > > > > > to recover the backup directory. It was taking a very long
> > time,
> > > > > and I
> > > > > > > > > restarted it with the -v8 hoping I might get some clue as to
> > what
> > > > > it
> > > > > > > > > was doing. Unfortunately after spitting out some
> > routine-looking
> > > > > > > > > output in the first few seconds it's now been running in
> > silence
> > > > > for
> > > > > > > > > nearly 12 hours.
> > > > > > > > >
> > > > > > > > > It's getting CPU time and I don't see any errors in syslog,
> > so I'm
> > > > > > > > > assuming that it's doing something. But I don't have any
> > idea what
> > > > > > > > > it's doing, if it's working correctly, or how much longer
> > it's
> > > > > likely
> > > > > > > > > to take.
> > > > > > > > >
> > > > > > > > > Is it normal that a regression takes this long? /backup is
> > > > > currently
> > > > > > > > > at 527 GB.
> > > > > > > > >
> > > > > > > > > Thanks.
> > > > > > > > >
> > > > > > > > > Walt
> > > > > > > > >
> > > > > > > > > _______________________________________________
> > > > > > > > > rdiff-backup-users mailing list at
> > [hidden email]
> > > > > > > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > > > > > > Wiki URL:
> > > > > > > > >
> > > > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> > > > > > >
> > > > > > > _______________________________________________
> > > > > > > rdiff-backup-users mailing list at [hidden email]
> > > > > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > > > > Wiki URL:
> > > > > > >
> > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> > > > >
> > > > > _______________________________________________
> > > > > rdiff-backup-users mailing list at [hidden email]
> > > > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > > > Wiki URL:
> > > > > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> >
> > > Mon Sep  9 20:09:56 2019  Using rdiff-backup version 1.2.8
> > > Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows
> > ACLs
> > > not supported by filesystem at /
> > > Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem
> > at /
> > > Mon Sep  9 20:09:57 2019
> > -----------------------------------------------------------------
> > > Detected abilities for source (read only) file system:
> > >   Access control lists                         On
> > >   Extended attributes                          On
> > >   Windows access control lists                 Off
> > >   Case sensitivity                             On
> > >   Escape DOS devices                           Off
> > >   Escape trailing spaces                       Off
> > >   Mac OS X style resource forks                Off
> > >   Mac OS X Finder information                  Off
> > > -----------------------------------------------------------------
> > > Mon Sep  9 20:09:57 2019  Making directory
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
> > > Mon Sep  9 20:09:57 2019  Making directory
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
> > > Mon Sep  9 20:09:57 2019  Hard linking
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl/hardlinked_file2 to
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
> > > Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows
> > ACLs
> > > not supported by filesystem at
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
> > > Mon Sep  9 20:09:57 2019  Touching
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file2
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
> > > Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem
> > at /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > > Mon Sep  9 20:09:57 2019  Deleting
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > > Mon Sep  9 20:09:57 2019  Removing directory
> > /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> > > Mon Sep  9 20:09:57 2019
> > -----------------------------------------------------------------
> > > Detected abilities for destination (read/write) file system:
> > >   Ownership changing                         Mon Sep  9 20:09:57 2019
> > Fatal Error: It appears that a previous rdiff-backup session with process
> > > id 4351 is still running.  If two different rdiff-backup processes write
> > > the same repository simultaneously, data corruption will probably
> > > result.  To proceed with regress anyway, rerun rdiff-backup with the
> > > --force option.
> > >   On
> > >   Hard linking                                 On
> > >   fsync() directories                          On
> > >   Directory inc permissions                    On
> > >   High-bit permissions                         On
> > >   Symlink permissions                          Off
> > >   Extended filenames                           On
> > >   Windows reserved filenames                   Off
> > >   Access control lists                         On
> > >   Extended attributes                          On
> > >   Windows access control lists                 Off
> > >   Case sensitivity                             On
> > >   Escape DOS devices                           Off
> > >   Escape trailing spaces                       Off
> > >   Mac OS X style resource forks                Off
> > >   Mac OS X Finder information                  Off
> > > -----------------------------------------------------------------
> > > Mon Sep  9 20:09:57 2019  Backup: must_escape_dos_devices = 0
> >
> > > _______________________________________________
> > > rdiff-backup-users mailing list at [hidden email]
> > > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > > Wiki URL:
> > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> >
> > _______________________________________________
> > rdiff-backup-users mailing list at [hidden email]
> > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > Wiki URL:
> > http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Ilario
As Dominic pointed out, I also suspect that the message refers to the
/tmp partition.
On some system, that partition is in RAM, so the available space on /tmp
may not relate to free disk space.
Can you try with the --tempdir (e.g. --tempdir /opt) option suggested by
Dominic?
Ciao,
Ilario

On 9/10/19 1:49 PM, Walt Mankowski wrote:

> It's not likely. That partition has 14 GB free.
>
> On Tue, Sep 10, 2019 at 07:52:38AM +0300, Dominic Raferd wrote:
>> Is it possible you are running out of temporary file space? You can specify
>> a different tmp location with switch --tempdir (or, if running to remote
>> server, --remote-tempdir). When checking an archive rdiff-backup may need a
>> lot of temporary space for all that unpacking. By the way, it may not be
>> apparent that the temporary file location is being used (or running out of
>> space) as the temporary files that rdiff-backup creates are not visible
>> there (there is some technical reason for this that I don't understand).
>>
>> On Tue, 10 Sep 2019 at 04:53, Walt Mankowski <[hidden email]> wrote:
>>
>>> I found a file named
>>>
>>>   rdiff-backup-data/current_mirror.2019-09-08T03:01:02-04:00.data
>>>
>>> which contained
>>>
>>>   4351
>>>
>>> I moved it out of the way and reran the backup command. This time it
>>> through an exception. The output is in the attached log file.
>>>
>>> Walt
>>>
>>> On Mon, Sep 09, 2019 at 08:17:04PM -0400, Walt Mankowski wrote:
>>>> I ran
>>>>
>>>>   $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist
>>> /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup.txt
>>>>
>>>> This time it exited right away. I've attached the log file, where the
>>>> key message is
>>>>
>>>>   Fatal Error: It appears that a previous rdiff-backup session with
>>>>   process id 4351 is still running.
>>>>
>>>> Process 4351 is /lib/systemd/systemd-resolved
>>>>
>>>> Is it safe to rerun it with --force?
>>>>
>>>> Walt
>>>>
>>>> On Mon, Sep 09, 2019 at 08:04:46PM -0400, Patrik Dufresne wrote:
>>>>> At this point, I would just kill all the rdiff-backup process. Then
>>>>> manually start the backup again to the USB drive. Run it with -v9 and
>>> post
>>>>> the logs here.
>>>>>
>>>>> That should provide us enough guidance about what is going on. Either
>>> the
>>>>> process will fail quickly (this is what I expect). If the process is
>>> taking
>>>>> too long, try to give us the logs that you gather.
>>>>>
>>>>> Since it's USB, could you check if the USB speed is alright ? If for
>>>>> whatever reason the USB speed switched from USB 3.0 to USB 2.0. It
>>> might
>>>>> take for ever to do a backup. You could double check this with "lsusb
>>> -t".
>>>>> Expect 5000M for USB 3
>>>>>
>>>>> ikus060@ikus060-laptop:~/workspace/HPUCA/hpuca-valuepack.git$ lsusb -t
>>>>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 10000M
>>>>>     |__ Port 4: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage,
>>> 5000M
>>>>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
>>>>>     |__ Port 5: Dev 14, If 0, Class=Hub, Driver=hub/3p, 480M
>>>>>
>>>>> A look to "dmesg" might also reveal some information about a change to
>>> the
>>>>> usb channel.
>>>>>
>>>>> --
>>>>> Patrik Dufresne Service Logiciel inc.
>>>>> http://www.patrikdufresne.com <http://patrikdufresne.com/>/
>>>>> 514-971-6442
>>>>> 130 rue Doris
>>>>> St-Colomban, QC J5K 1T9
>>>>>
>>>>>
>>>>> On Mon, Sep 9, 2019 at 7:47 PM Walt Mankowski <[hidden email]>
>>> wrote:
>>>>>
>>>>>> On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
>>>>>>> Hum, this is strange. It should not fail with a "no space left on
>>>>>> device".
>>>>>>
>>>>>> Agreed! That's why I originally thought it must have been some sort
>>> of
>>>>>> USB glitch.
>>>>>>
>>>>>>> Could you provide the log generate with -v9 ? Plz provide the full
>>>>>> command
>>>>>>> line you used.
>>>>>>
>>>>>> So kill the run with -v8?
>>>>>>
>>>>>>> What is the filesystem of your USB drive ?
>>>>>>
>>>>>> ext4
>>>>>>
>>>>>>> If you try to run the backup again do you have an error?
>>>>>>
>>>>>> In fact that happened last night. My normal nightly backup kicked in
>>>>>> while a previous attempt at running --check-destination-dir was still
>>>>>> running. The cronjob reported:
>>>>>>
>>>>>>   Previous backup seems to have failed, regressing destination now.
>>>>>>   Fatal Error: Killed with signal 15
>>>>>>
>>>>>> The latter was when I killed it when I woke up and saw that both of
>>>>>> them were running.
>>>>>>
>>>>>> Walt
>>>>>>
>>>>>>> On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]>
>>> wrote:
>>>>>>>
>>>>>>>> Good idea! But unfortunately it doesn't seem to be the problem:
>>>>>>>>
>>>>>>>> % df -hi /backup
>>>>>>>> Filesystem     Inodes IUsed IFree IUse% Mounted on
>>>>>>>> /dev/sde1        117M   19M   98M   17% /backup
>>>>>>>>
>>>>>>>>
>>>>>>>> On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
>>>>>>>>> Hello Walt, could you double check the disk space. Especially
>>> the
>>>>>> number
>>>>>>>> of
>>>>>>>>> inode ? It's probably the root cause of your issue.
>>>>>>>>>
>>>>>>>>> On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <
>>> [hidden email]>
>>>>>> wrote:
>>>>>>>>>
>>>>>>>>>> I've been running rdiff-backup to an external USB drive for
>>> years
>>>>>>>>>> without any problems. Over the weekend my backup failed with
>>>>>>>>>>
>>>>>>>>>>   Exception '[Errno 28] No space left on device
>>>>>>>>>>
>>>>>>>>>> This is odd, since there is 1.2 TB free on the drive. I
>>> didn't see
>>>>>> any
>>>>>>>>>> errors in syslog, and I was able to create a new file on the
>>> drive
>>>>>>>>>> without any problem.
>>>>>>>>>>
>>>>>>>>>> Thinking it might have been a USB glitch I rebooted the
>>> machine and
>>>>>>>>>> now I'm running
>>>>>>>>>>
>>>>>>>>>>   rdiff-backup --check-destination-dir
>>>>>>>>>>
>>>>>>>>>> to recover the backup directory. It was taking a very long
>>> time,
>>>>>> and I
>>>>>>>>>> restarted it with the -v8 hoping I might get some clue as to
>>> what
>>>>>> it
>>>>>>>>>> was doing. Unfortunately after spitting out some
>>> routine-looking
>>>>>>>>>> output in the first few seconds it's now been running in
>>> silence
>>>>>> for
>>>>>>>>>> nearly 12 hours.
>>>>>>>>>>
>>>>>>>>>> It's getting CPU time and I don't see any errors in syslog,
>>> so I'm
>>>>>>>>>> assuming that it's doing something. But I don't have any
>>> idea what
>>>>>>>>>> it's doing, if it's working correctly, or how much longer
>>> it's
>>>>>> likely
>>>>>>>>>> to take.
>>>>>>>>>>
>>>>>>>>>> Is it normal that a regression takes this long? /backup is
>>>>>> currently
>>>>>>>>>> at 527 GB.
>>>>>>>>>>
>>>>>>>>>> Thanks.
>>>>>>>>>>
>>>>>>>>>> Walt
>>>>>>>>>>
>>>>>>>>>> _______________________________________________
>>>>>>>>>> rdiff-backup-users mailing list at
>>> [hidden email]
>>>>>>>>>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
>>>>>>>>>> Wiki URL:
>>>>>>>>>>
>>>>>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>>>>>>>>
>>>>>>>> _______________________________________________
>>>>>>>> rdiff-backup-users mailing list at [hidden email]
>>>>>>>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
>>>>>>>> Wiki URL:
>>>>>>>>
>>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>>>>>>
>>>>>> _______________________________________________
>>>>>> rdiff-backup-users mailing list at [hidden email]
>>>>>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
>>>>>> Wiki URL:
>>>>>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>>>
>>>> Mon Sep  9 20:09:56 2019  Using rdiff-backup version 1.2.8
>>>> Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows
>>> ACLs
>>>> not supported by filesystem at /
>>>> Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem
>>> at /
>>>> Mon Sep  9 20:09:57 2019
>>> -----------------------------------------------------------------
>>>> Detected abilities for source (read only) file system:
>>>>   Access control lists                         On
>>>>   Extended attributes                          On
>>>>   Windows access control lists                 Off
>>>>   Case sensitivity                             On
>>>>   Escape DOS devices                           Off
>>>>   Escape trailing spaces                       Off
>>>>   Mac OS X style resource forks                Off
>>>>   Mac OS X Finder information                  Off
>>>> -----------------------------------------------------------------
>>>> Mon Sep  9 20:09:57 2019  Making directory
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
>>>> Mon Sep  9 20:09:57 2019  Making directory
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
>>>> Mon Sep  9 20:09:57 2019  Hard linking
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl/hardlinked_file2 to
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
>>>> Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows
>>> ACLs
>>>> not supported by filesystem at
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
>>>> Mon Sep  9 20:09:57 2019  Touching
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file2
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
>>>> Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem
>>> at /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>>>> Mon Sep  9 20:09:57 2019  Deleting
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>>>> Mon Sep  9 20:09:57 2019  Removing directory
>>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>>>> Mon Sep  9 20:09:57 2019
>>> -----------------------------------------------------------------
>>>> Detected abilities for destination (read/write) file system:
>>>>   Ownership changing                         Mon Sep  9 20:09:57 2019
>>> Fatal Error: It appears that a previous rdiff-backup session with process
>>>> id 4351 is still running.  If two different rdiff-backup processes write
>>>> the same repository simultaneously, data corruption will probably
>>>> result.  To proceed with regress anyway, rerun rdiff-backup with the
>>>> --force option.
>>>>   On
>>>>   Hard linking                                 On
>>>>   fsync() directories                          On
>>>>   Directory inc permissions                    On
>>>>   High-bit permissions                         On
>>>>   Symlink permissions                          Off
>>>>   Extended filenames                           On
>>>>   Windows reserved filenames                   Off
>>>>   Access control lists                         On
>>>>   Extended attributes                          On
>>>>   Windows access control lists                 Off
>>>>   Case sensitivity                             On
>>>>   Escape DOS devices                           Off
>>>>   Escape trailing spaces                       Off
>>>>   Mac OS X style resource forks                Off
>>>>   Mac OS X Finder information                  Off
>>>> -----------------------------------------------------------------
>>>> Mon Sep  9 20:09:57 2019  Backup: must_escape_dos_devices = 0

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki

signature.asc (201 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Walt Mankowski
Thanks for the suggestions, but while that might have caused the
problem over the weekend, the most recent log I posted failed on a
completely different exception:

Traceback (most recent call last):
  File "/usr/bin/rdiff-backup", line 30, in <module>
    rdiff_backup.Main.error_check_Main(sys.argv[1:])
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/Main.py", line 304, in error_check_Main                                                                          
    try: Main(arglist)
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/Main.py", line 324, in Main
    take_action(rps)
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/Main.py", line 280, in take_action                                                                              
    elif action == "backup": Backup(rps[0], rps[1])
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/Main.py", line 343, in Backup
    backup.Mirror_and_increment(rpin, rpout, incdir)
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/backup.py", line 51, in Mirror_and_increment                                                                    
    DestS.patch_and_increment(dest_rpath, source_diffiter, inc_rpath)
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/backup.py", line 243, in patch_and_increment                                                                    
    ITR(diff.index, diff)
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/rorpiter.py", line 268, in __call__                                                                              
    else: self.root_branch.start_process(*args)
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/backup.py", line 721, in start_process                                                                          
    inc = increment.Increment(diff_rorp, self.base_rp, inc_prefix)
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/increment.py", line 41, in Increment                                                                            
    elif mirror.isdir(): incrp = makedir(mirror, incpref)
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/increment.py", line 103, in makedir                                                                              
    dirsign = get_inc(incpref, "dir")
  File "/usr/lib/python2.7/dist-packages/rdiff_backup/increment.py", line 123, in get_inc                                                                              
    assert not incrp.lstat(), incrp
AssertionError: Path: /backup/scruffy/rdiff-backup-data/increments.2019-09-07T03:01:01-04:00.dir                                                                      
Index: ('increments.2019-09-07T03:01:01-04:00.dir',)
Data: {'acl': <rdiff_backup.eas_acls.AccessControlLists instance at 0x7ff36b8edc68>, 'uid': 0, 'perms': 493, 'type': 'reg', 'gname': 'root', 'ea': <rdiff_backup.eas_acls.ExtendedAttributes instance at 0x7ff36b8edc20>, 'ctime': 1567926069, 'devloc': 2113L, 'uname': 'root', 'nlink': 1, 'gid': 0, 'mtime': 1567531730, 'atime': 1567926069, 'inode': 29941839, 'size': 0}


On Tue, Sep 10, 2019 at 02:36:00PM +0200, Ilario Gelmetti wrote:

> As Dominic pointed out, I also suspect that the message refers to the
> /tmp partition.
> On some system, that partition is in RAM, so the available space on /tmp
> may not relate to free disk space.
> Can you try with the --tempdir (e.g. --tempdir /opt) option suggested by
> Dominic?
> Ciao,
> Ilario
>
> On 9/10/19 1:49 PM, Walt Mankowski wrote:
> > It's not likely. That partition has 14 GB free.
> >
> > On Tue, Sep 10, 2019 at 07:52:38AM +0300, Dominic Raferd wrote:
> >> Is it possible you are running out of temporary file space? You can specify
> >> a different tmp location with switch --tempdir (or, if running to remote
> >> server, --remote-tempdir). When checking an archive rdiff-backup may need a
> >> lot of temporary space for all that unpacking. By the way, it may not be
> >> apparent that the temporary file location is being used (or running out of
> >> space) as the temporary files that rdiff-backup creates are not visible
> >> there (there is some technical reason for this that I don't understand).
> >>
> >> On Tue, 10 Sep 2019 at 04:53, Walt Mankowski <[hidden email]> wrote:
> >>
> >>> I found a file named
> >>>
> >>>   rdiff-backup-data/current_mirror.2019-09-08T03:01:02-04:00.data
> >>>
> >>> which contained
> >>>
> >>>   4351
> >>>
> >>> I moved it out of the way and reran the backup command. This time it
> >>> through an exception. The output is in the attached log file.
> >>>
> >>> Walt
> >>>
> >>> On Mon, Sep 09, 2019 at 08:17:04PM -0400, Walt Mankowski wrote:
> >>>> I ran
> >>>>
> >>>>   $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist
> >>> /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup.txt
> >>>>
> >>>> This time it exited right away. I've attached the log file, where the
> >>>> key message is
> >>>>
> >>>>   Fatal Error: It appears that a previous rdiff-backup session with
> >>>>   process id 4351 is still running.
> >>>>
> >>>> Process 4351 is /lib/systemd/systemd-resolved
> >>>>
> >>>> Is it safe to rerun it with --force?
> >>>>
> >>>> Walt
> >>>>
> >>>> On Mon, Sep 09, 2019 at 08:04:46PM -0400, Patrik Dufresne wrote:
> >>>>> At this point, I would just kill all the rdiff-backup process. Then
> >>>>> manually start the backup again to the USB drive. Run it with -v9 and
> >>> post
> >>>>> the logs here.
> >>>>>
> >>>>> That should provide us enough guidance about what is going on. Either
> >>> the
> >>>>> process will fail quickly (this is what I expect). If the process is
> >>> taking
> >>>>> too long, try to give us the logs that you gather.
> >>>>>
> >>>>> Since it's USB, could you check if the USB speed is alright ? If for
> >>>>> whatever reason the USB speed switched from USB 3.0 to USB 2.0. It
> >>> might
> >>>>> take for ever to do a backup. You could double check this with "lsusb
> >>> -t".
> >>>>> Expect 5000M for USB 3
> >>>>>
> >>>>> ikus060@ikus060-laptop:~/workspace/HPUCA/hpuca-valuepack.git$ lsusb -t
> >>>>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 10000M
> >>>>>     |__ Port 4: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage,
> >>> 5000M
> >>>>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
> >>>>>     |__ Port 5: Dev 14, If 0, Class=Hub, Driver=hub/3p, 480M
> >>>>>
> >>>>> A look to "dmesg" might also reveal some information about a change to
> >>> the
> >>>>> usb channel.
> >>>>>
> >>>>> --
> >>>>> Patrik Dufresne Service Logiciel inc.
> >>>>> http://www.patrikdufresne.com <http://patrikdufresne.com/>/
> >>>>> 514-971-6442
> >>>>> 130 rue Doris
> >>>>> St-Colomban, QC J5K 1T9
> >>>>>
> >>>>>
> >>>>> On Mon, Sep 9, 2019 at 7:47 PM Walt Mankowski <[hidden email]>
> >>> wrote:
> >>>>>
> >>>>>> On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
> >>>>>>> Hum, this is strange. It should not fail with a "no space left on
> >>>>>> device".
> >>>>>>
> >>>>>> Agreed! That's why I originally thought it must have been some sort
> >>> of
> >>>>>> USB glitch.
> >>>>>>
> >>>>>>> Could you provide the log generate with -v9 ? Plz provide the full
> >>>>>> command
> >>>>>>> line you used.
> >>>>>>
> >>>>>> So kill the run with -v8?
> >>>>>>
> >>>>>>> What is the filesystem of your USB drive ?
> >>>>>>
> >>>>>> ext4
> >>>>>>
> >>>>>>> If you try to run the backup again do you have an error?
> >>>>>>
> >>>>>> In fact that happened last night. My normal nightly backup kicked in
> >>>>>> while a previous attempt at running --check-destination-dir was still
> >>>>>> running. The cronjob reported:
> >>>>>>
> >>>>>>   Previous backup seems to have failed, regressing destination now.
> >>>>>>   Fatal Error: Killed with signal 15
> >>>>>>
> >>>>>> The latter was when I killed it when I woke up and saw that both of
> >>>>>> them were running.
> >>>>>>
> >>>>>> Walt
> >>>>>>
> >>>>>>> On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]>
> >>> wrote:
> >>>>>>>
> >>>>>>>> Good idea! But unfortunately it doesn't seem to be the problem:
> >>>>>>>>
> >>>>>>>> % df -hi /backup
> >>>>>>>> Filesystem     Inodes IUsed IFree IUse% Mounted on
> >>>>>>>> /dev/sde1        117M   19M   98M   17% /backup
> >>>>>>>>
> >>>>>>>>
> >>>>>>>> On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
> >>>>>>>>> Hello Walt, could you double check the disk space. Especially
> >>> the
> >>>>>> number
> >>>>>>>> of
> >>>>>>>>> inode ? It's probably the root cause of your issue.
> >>>>>>>>>
> >>>>>>>>> On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <
> >>> [hidden email]>
> >>>>>> wrote:
> >>>>>>>>>
> >>>>>>>>>> I've been running rdiff-backup to an external USB drive for
> >>> years
> >>>>>>>>>> without any problems. Over the weekend my backup failed with
> >>>>>>>>>>
> >>>>>>>>>>   Exception '[Errno 28] No space left on device
> >>>>>>>>>>
> >>>>>>>>>> This is odd, since there is 1.2 TB free on the drive. I
> >>> didn't see
> >>>>>> any
> >>>>>>>>>> errors in syslog, and I was able to create a new file on the
> >>> drive
> >>>>>>>>>> without any problem.
> >>>>>>>>>>
> >>>>>>>>>> Thinking it might have been a USB glitch I rebooted the
> >>> machine and
> >>>>>>>>>> now I'm running
> >>>>>>>>>>
> >>>>>>>>>>   rdiff-backup --check-destination-dir
> >>>>>>>>>>
> >>>>>>>>>> to recover the backup directory. It was taking a very long
> >>> time,
> >>>>>> and I
> >>>>>>>>>> restarted it with the -v8 hoping I might get some clue as to
> >>> what
> >>>>>> it
> >>>>>>>>>> was doing. Unfortunately after spitting out some
> >>> routine-looking
> >>>>>>>>>> output in the first few seconds it's now been running in
> >>> silence
> >>>>>> for
> >>>>>>>>>> nearly 12 hours.
> >>>>>>>>>>
> >>>>>>>>>> It's getting CPU time and I don't see any errors in syslog,
> >>> so I'm
> >>>>>>>>>> assuming that it's doing something. But I don't have any
> >>> idea what
> >>>>>>>>>> it's doing, if it's working correctly, or how much longer
> >>> it's
> >>>>>> likely
> >>>>>>>>>> to take.
> >>>>>>>>>>
> >>>>>>>>>> Is it normal that a regression takes this long? /backup is
> >>>>>> currently
> >>>>>>>>>> at 527 GB.
> >>>>>>>>>>
> >>>>>>>>>> Thanks.
> >>>>>>>>>>
> >>>>>>>>>> Walt
> >>>>>>>>>>
> >>>>>>>>>> _______________________________________________
> >>>>>>>>>> rdiff-backup-users mailing list at
> >>> [hidden email]
> >>>>>>>>>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> >>>>>>>>>> Wiki URL:
> >>>>>>>>>>
> >>>>>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> >>>>>>>>
> >>>>>>>> _______________________________________________
> >>>>>>>> rdiff-backup-users mailing list at [hidden email]
> >>>>>>>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> >>>>>>>> Wiki URL:
> >>>>>>>>
> >>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> >>>>>>
> >>>>>> _______________________________________________
> >>>>>> rdiff-backup-users mailing list at [hidden email]
> >>>>>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> >>>>>> Wiki URL:
> >>>>>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> >>>
> >>>> Mon Sep  9 20:09:56 2019  Using rdiff-backup version 1.2.8
> >>>> Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows
> >>> ACLs
> >>>> not supported by filesystem at /
> >>>> Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem
> >>> at /
> >>>> Mon Sep  9 20:09:57 2019
> >>> -----------------------------------------------------------------
> >>>> Detected abilities for source (read only) file system:
> >>>>   Access control lists                         On
> >>>>   Extended attributes                          On
> >>>>   Windows access control lists                 Off
> >>>>   Case sensitivity                             On
> >>>>   Escape DOS devices                           Off
> >>>>   Escape trailing spaces                       Off
> >>>>   Mac OS X style resource forks                Off
> >>>>   Mac OS X Finder information                  Off
> >>>> -----------------------------------------------------------------
> >>>> Mon Sep  9 20:09:57 2019  Making directory
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
> >>>> Mon Sep  9 20:09:57 2019  Making directory
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
> >>>> Mon Sep  9 20:09:57 2019  Hard linking
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl/hardlinked_file2 to
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
> >>>> Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows
> >>> ACLs
> >>>> not supported by filesystem at
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
> >>>> Mon Sep  9 20:09:57 2019  Touching
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file2
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
> >>>> Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem
> >>> at /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> >>>> Mon Sep  9 20:09:57 2019  Deleting
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> >>>> Mon Sep  9 20:09:57 2019  Removing directory
> >>> /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
> >>>> Mon Sep  9 20:09:57 2019
> >>> -----------------------------------------------------------------
> >>>> Detected abilities for destination (read/write) file system:
> >>>>   Ownership changing                         Mon Sep  9 20:09:57 2019
> >>> Fatal Error: It appears that a previous rdiff-backup session with process
> >>>> id 4351 is still running.  If two different rdiff-backup processes write
> >>>> the same repository simultaneously, data corruption will probably
> >>>> result.  To proceed with regress anyway, rerun rdiff-backup with the
> >>>> --force option.
> >>>>   On
> >>>>   Hard linking                                 On
> >>>>   fsync() directories                          On
> >>>>   Directory inc permissions                    On
> >>>>   High-bit permissions                         On
> >>>>   Symlink permissions                          Off
> >>>>   Extended filenames                           On
> >>>>   Windows reserved filenames                   Off
> >>>>   Access control lists                         On
> >>>>   Extended attributes                          On
> >>>>   Windows access control lists                 Off
> >>>>   Case sensitivity                             On
> >>>>   Escape DOS devices                           Off
> >>>>   Escape trailing spaces                       Off
> >>>>   Mac OS X style resource forks                Off
> >>>>   Mac OS X Finder information                  Off
> >>>> -----------------------------------------------------------------
> >>>> Mon Sep  9 20:09:57 2019  Backup: must_escape_dos_devices = 0
>




> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki


_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Eric Lavarde
In reply to this post by Walt Mankowski
Hi Walt,

On 10/09/2019 03:53, Walt Mankowski wrote:

> I found a file named
>
>    rdiff-backup-data/current_mirror.2019-09-08T03:01:02-04:00.data
>
> which contained
>
>    4351
>
> I moved it out of the way and reran the backup command. This time it
> through an exception. The output is in the attached log file.

That wasn't a good idea: the current_mirror file is NOT a temporary
file, it actually tells rdiff-backup the date and time of the last
version of your backup. _Two_ current_mirror files tells rdiff-backup
that something went wrong during the last backup and that it should do a
roll-back/regress.

You only had the bad luck to have a process with the same PID as
documented in the file, so that rdiff-backup thought that a 2nd backup
is going on. This is weak and we should fix it.

This said, removing the file confused completely rdiff-backup and I'm
not sure how much is to save.

I can from now on recommend only one of two courses of action:

- if you don't care about the history of your backups, just start from
scratch a new backup repo and forget about the whole thing.
- if the history is important to you, you could try to recreate the file
you deleted and see if rdiff-backup is still able to correct the
repository, but without any guarantee. In your place, I would do before
a copy of the repo to make sure you don't break it even more.

KR, Eric

>
> Walt
>
> On Mon, Sep 09, 2019 at 08:17:04PM -0400, Walt Mankowski wrote:
>> I ran
>>
>>    $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup.txt
>>
>> This time it exited right away. I've attached the log file, where the
>> key message is
>>
>>    Fatal Error: It appears that a previous rdiff-backup session with
>>    process id 4351 is still running.
>>
>> Process 4351 is /lib/systemd/systemd-resolved
>>
>> Is it safe to rerun it with --force?
>>
>> Walt
>>
>> On Mon, Sep 09, 2019 at 08:04:46PM -0400, Patrik Dufresne wrote:
>>> At this point, I would just kill all the rdiff-backup process. Then
>>> manually start the backup again to the USB drive. Run it with -v9 and post
>>> the logs here.
>>>
>>> That should provide us enough guidance about what is going on. Either the
>>> process will fail quickly (this is what I expect). If the process is taking
>>> too long, try to give us the logs that you gather.
>>>
>>> Since it's USB, could you check if the USB speed is alright ? If for
>>> whatever reason the USB speed switched from USB 3.0 to USB 2.0. It might
>>> take for ever to do a backup. You could double check this with "lsusb -t".
>>> Expect 5000M for USB 3
>>>
>>> ikus060@ikus060-laptop:~/workspace/HPUCA/hpuca-valuepack.git$ lsusb -t
>>> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 10000M
>>>      |__ Port 4: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage, 5000M
>>> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
>>>      |__ Port 5: Dev 14, If 0, Class=Hub, Driver=hub/3p, 480M
>>>
>>> A look to "dmesg" might also reveal some information about a change to the
>>> usb channel.
>>>
>>> --
>>> Patrik Dufresne Service Logiciel inc.
>>> http://www.patrikdufresne.com <http://patrikdufresne.com/>/
>>> 514-971-6442
>>> 130 rue Doris
>>> St-Colomban, QC J5K 1T9
>>>
>>>
>>> On Mon, Sep 9, 2019 at 7:47 PM Walt Mankowski <[hidden email]> wrote:
>>>
>>>> On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
>>>>> Hum, this is strange. It should not fail with a "no space left on
>>>> device".
>>>>
>>>> Agreed! That's why I originally thought it must have been some sort of
>>>> USB glitch.
>>>>
>>>>> Could you provide the log generate with -v9 ? Plz provide the full
>>>> command
>>>>> line you used.
>>>>
>>>> So kill the run with -v8?
>>>>
>>>>> What is the filesystem of your USB drive ?
>>>>
>>>> ext4
>>>>
>>>>> If you try to run the backup again do you have an error?
>>>>
>>>> In fact that happened last night. My normal nightly backup kicked in
>>>> while a previous attempt at running --check-destination-dir was still
>>>> running. The cronjob reported:
>>>>
>>>>    Previous backup seems to have failed, regressing destination now.
>>>>    Fatal Error: Killed with signal 15
>>>>
>>>> The latter was when I killed it when I woke up and saw that both of
>>>> them were running.
>>>>
>>>> Walt
>>>>
>>>>> On Mon, Sep 9, 2019, 7:33 PM Walt Mankowski, <[hidden email]> wrote:
>>>>>
>>>>>> Good idea! But unfortunately it doesn't seem to be the problem:
>>>>>>
>>>>>> % df -hi /backup
>>>>>> Filesystem     Inodes IUsed IFree IUse% Mounted on
>>>>>> /dev/sde1        117M   19M   98M   17% /backup
>>>>>>
>>>>>>
>>>>>> On Mon, Sep 09, 2019 at 07:23:14PM -0400, Patrik Dufresne wrote:
>>>>>>> Hello Walt, could you double check the disk space. Especially the
>>>> number
>>>>>> of
>>>>>>> inode ? It's probably the root cause of your issue.
>>>>>>>
>>>>>>> On Mon, Sep 9, 2019, 7:19 PM Walt Mankowski, <[hidden email]>
>>>> wrote:
>>>>>>>
>>>>>>>> I've been running rdiff-backup to an external USB drive for years
>>>>>>>> without any problems. Over the weekend my backup failed with
>>>>>>>>
>>>>>>>>    Exception '[Errno 28] No space left on device
>>>>>>>>
>>>>>>>> This is odd, since there is 1.2 TB free on the drive. I didn't see
>>>> any
>>>>>>>> errors in syslog, and I was able to create a new file on the drive
>>>>>>>> without any problem.
>>>>>>>>
>>>>>>>> Thinking it might have been a USB glitch I rebooted the machine and
>>>>>>>> now I'm running
>>>>>>>>
>>>>>>>>    rdiff-backup --check-destination-dir
>>>>>>>>
>>>>>>>> to recover the backup directory. It was taking a very long time,
>>>> and I
>>>>>>>> restarted it with the -v8 hoping I might get some clue as to what
>>>> it
>>>>>>>> was doing. Unfortunately after spitting out some routine-looking
>>>>>>>> output in the first few seconds it's now been running in silence
>>>> for
>>>>>>>> nearly 12 hours.
>>>>>>>>
>>>>>>>> It's getting CPU time and I don't see any errors in syslog, so I'm
>>>>>>>> assuming that it's doing something. But I don't have any idea what
>>>>>>>> it's doing, if it's working correctly, or how much longer it's
>>>> likely
>>>>>>>> to take.
>>>>>>>>
>>>>>>>> Is it normal that a regression takes this long? /backup is
>>>> currently
>>>>>>>> at 527 GB.
>>>>>>>>
>>>>>>>> Thanks.
>>>>>>>>
>>>>>>>> Walt
>>>>>>>>
>>>>>>>> _______________________________________________
>>>>>>>> rdiff-backup-users mailing list at [hidden email]
>>>>>>>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
>>>>>>>> Wiki URL:
>>>>>>>>
>>>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>>>>>>
>>>>>> _______________________________________________
>>>>>> rdiff-backup-users mailing list at [hidden email]
>>>>>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
>>>>>> Wiki URL:
>>>>>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>>>>
>>>> _______________________________________________
>>>> rdiff-backup-users mailing list at [hidden email]
>>>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
>>>> Wiki URL:
>>>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>
>> Mon Sep  9 20:09:56 2019  Using rdiff-backup version 1.2.8
>> Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows ACLs
>> not supported by filesystem at /
>> Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem at /
>> Mon Sep  9 20:09:57 2019  -----------------------------------------------------------------
>> Detected abilities for source (read only) file system:
>>    Access control lists                         On
>>    Extended attributes                          On
>>    Windows access control lists                 Off
>>    Case sensitivity                             On
>>    Escape DOS devices                           Off
>>    Escape trailing spaces                       Off
>>    Mac OS X style resource forks                Off
>>    Mac OS X Finder information                  Off
>> -----------------------------------------------------------------
>> Mon Sep  9 20:09:57 2019  Making directory /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/5-_ a.snapshot.gz
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/uniᄉ
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/:\"
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/A
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/foo
>> Mon Sep  9 20:09:57 2019  Making directory /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
>> Mon Sep  9 20:09:57 2019  Hard linking /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hl/hardlinked_file2 to /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
>> Mon Sep  9 20:09:57 2019  Unable to import win32security module. Windows ACLs
>> not supported by filesystem at /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/regfile
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
>> Mon Sep  9 20:09:57 2019  Touching /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file2
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
>> Mon Sep  9 20:09:57 2019  escape_dos_devices not required by filesystem at /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>> Mon Sep  9 20:09:57 2019  Deleting /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>> Mon Sep  9 20:09:57 2019  Removing directory /backup/scruffy/rdiff-backup-data/rdiff-backup.tmp.0
>> Mon Sep  9 20:09:57 2019  -----------------------------------------------------------------
>> Detected abilities for destination (read/write) file system:
>>    Ownership changing                         Mon Sep  9 20:09:57 2019  Fatal Error: It appears that a previous rdiff-backup session with process
>> id 4351 is still running.  If two different rdiff-backup processes write
>> the same repository simultaneously, data corruption will probably
>> result.  To proceed with regress anyway, rerun rdiff-backup with the
>> --force option.
>>    On
>>    Hard linking                                 On
>>    fsync() directories                          On
>>    Directory inc permissions                    On
>>    High-bit permissions                         On
>>    Symlink permissions                          Off
>>    Extended filenames                           On
>>    Windows reserved filenames                   Off
>>    Access control lists                         On
>>    Extended attributes                          On
>>    Windows access control lists                 Off
>>    Case sensitivity                             On
>>    Escape DOS devices                           Off
>>    Escape trailing spaces                       Off
>>    Mac OS X style resource forks                Off
>>    Mac OS X Finder information                  Off
>> -----------------------------------------------------------------
>> Mon Sep  9 20:09:57 2019  Backup: must_escape_dos_devices = 0
>
>> _______________________________________________
>> rdiff-backup-users mailing list at [hidden email]
>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
>> Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>
>
> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Joe Steele-2
In reply to this post by Walt Mankowski
On 9/9/2019 9:53 PM, Walt Mankowski wrote:

> I found a file named
>
>    rdiff-backup-data/current_mirror.2019-09-08T03:01:02-04:00.data
>
> which contained
>
>    4351
>
> I moved it out of the way and reran the backup command. This time it
> through an exception. The output is in the attached log file.
>

(Some of the following echoes what Eric Lavarde wrote a few minutes ago.)

Moving a current_mirror file out of the way is never a good thing to do.
  Having 2 current_mirror files is how rdiff-backup knows that the last
backup failed and that a regression is necessary in order to reestablish
a consistent state for the backup repository.

Fortunately, it looks as though your attempt to run another backup after
removing the current_mirror file did not get anywhere (based on your log).

I suggest putting the 'current_mirror.2019-09-08T03:01:02-04:00.data'
back in place (and possibly restart systemd-resolved, as commented
further below).  After that, I would look to see what current mirror
files you now have.  My guess is that you will find the following:

current_mirror.2019-09-07T03:01:01-04:00.data
current_mirror.2019-09-08T03:01:02-04:00.data
current_mirror.2019-09-09T21:46:29-04:00.data

9/7/19 is your last good backup.  9/8 was the backup that failed.  9/9
was your most recent attempt to fix things.

*Assuming* that I am correct about the current_mirror files that exist,
then I would remove the last of those files
(current_mirror.2019-09-09T21:46:29-04:00.data).  Yes, that's contrary
to my admonition above.  But rdiff-backup cannot deal with 3 such files,
and this last file is from your most recent backup that did not get
anywhere, according to your log.

I would then again try 'rdiff-backup --check-destination-dir' (and cross
your fingers).

Your original concern was that this was taking forever (12+ hours and
counting).  For what it is worth, my experience is that regressions do
take many hours (depending on size of your current mirror), and they
leave you wondering if anything is actually happening.

It seems like 296 GB would take me 4-8 hours to regress (I can't really
remember -- it's been a while).  If your backup is 527 GB (i.e., that's
what shows up for 'MirrorFileSize' in your session_statistics.* files),
then yes, I imagine that would take quite some time to regress.  There
are probably other factors besides size that affect the speed -- disk
speed, processor speed, load, etc.  I don't know if rdiff-backup logging
verbosity is a factor or not -- I would think that it might be a factor.

None of the above addresses your problem with "No space left on device".
  I would try to restore your repository to a consistent state before
investigating that further.  (Of course, the real frustrating thing is
that if the backup fails again, you are forced to wait many hours while
you repeat the regression of the failed backup.)

<snip>

> On Mon, Sep 09, 2019 at 08:17:04PM -0400, Walt Mankowski wrote:
>> I ran
>>
>>    $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup.txt
>>
>> This time it exited right away. I've attached the log file, where the
>> key message is
>>
>>    Fatal Error: It appears that a previous rdiff-backup session with
>>    process id 4351 is still running.
>>
>> Process 4351 is /lib/systemd/systemd-resolved
>>

It would seem that you had a bit of bad luck in that a process ID that
had been used for a crashed rdiff-backup session happened to now be in
use again for an unrelated process (systemd-resolved).

>> Is it safe to rerun it with --force?
>>

Using --force would have gotten around the Fatal Error, but it would
have also forced other things to happen that you may not want.  In this
instance, I would have probably restarted systemd-resolved so that it
used a different PID.  That should have gotten rdiff-backup past that
particular error.

<snip>

>>> On Mon, Sep 9, 2019 at 7:47 PM Walt Mankowski <[hidden email]> wrote:
>>>
>>>> On Mon, Sep 09, 2019 at 07:38:52PM -0400, Patrik Dufresne wrote:
>>>>> Hum, this is strange. It should not fail with a "no space left on
>>>> device".
>>>>
>>>> Agreed! That's why I originally thought it must have been some sort of
>>>> USB glitch.
>>>>
>>>>> Could you provide the log generate with -v9 ? Plz provide the full
>>>> command
>>>>> line you used.
>>>>
>>>> So kill the run with -v8?
>>>>
>>>>> What is the filesystem of your USB drive ?
>>>>
>>>> ext4
>>>>
>>>>> If you try to run the backup again do you have an error?
>>>>
>>>> In fact that happened last night. My normal nightly backup kicked in
>>>> while a previous attempt at running --check-destination-dir was still
>>>> running. The cronjob reported:
>>>>
>>>>    Previous backup seems to have failed, regressing destination now.
>>>>    Fatal Error: Killed with signal 15
>>>>
>>>> The latter was when I killed it when I woke up and saw that both of
>>>> them were running.
>>>>

That's interesting.  That points out that rdiff-backup does not check if
a regression is already in progress before starting another one.  That
needs fixing.

--Joe


_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Walt Mankowski
On Tue, Sep 10, 2019 at 03:25:12PM -0400, Joe Steele wrote:

> On 9/9/2019 9:53 PM, Walt Mankowski wrote:
> > I found a file named
> >
> >    rdiff-backup-data/current_mirror.2019-09-08T03:01:02-04:00.data
> >
> > which contained
> >
> >    4351
> >
> > I moved it out of the way and reran the backup command. This time it
> > through an exception. The output is in the attached log file.
> >
>
> (Some of the following echoes what Eric Lavarde wrote a few minutes ago.)
>
> Moving a current_mirror file out of the way is never a good thing to do.
> Having 2 current_mirror files is how rdiff-backup knows that the last backup
> failed and that a regression is necessary in order to reestablish a
> consistent state for the backup repository.
>
> Fortunately, it looks as though your attempt to run another backup after
> removing the current_mirror file did not get anywhere (based on your log).
>
> I suggest putting the 'current_mirror.2019-09-08T03:01:02-04:00.data' back
> in place (and possibly restart systemd-resolved, as commented further
> below).  After that, I would look to see what current mirror files you now
> have.  My guess is that you will find the following:
>
> current_mirror.2019-09-07T03:01:01-04:00.data
> current_mirror.2019-09-08T03:01:02-04:00.data
> current_mirror.2019-09-09T21:46:29-04:00.data
>
> 9/7/19 is your last good backup.  9/8 was the backup that failed.  9/9 was
> your most recent attempt to fix things.
>
> *Assuming* that I am correct about the current_mirror files that exist, then
> I would remove the last of those files
> (current_mirror.2019-09-09T21:46:29-04:00.data).  Yes, that's contrary to my
> admonition above.  But rdiff-backup cannot deal with 3 such files, and this
> last file is from your most recent backup that did not get anywhere,
> according to your log.
>
> I would then again try 'rdiff-backup --check-destination-dir' (and cross
> your fingers).

Oops!

What I ended up doing was moving the file back and removing these files:

  current_mirror.2019-09-09T21:46:28-04:00.data
  file_statistics.2019-09-09T21:46:28-04:00.data.gz

Then, since I hadn't read your email yet, I reran the backup command again:

  $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup3.txt

That seems to have done the trick. It printed out a bunch of text and
finally said

  Previous backup seems to have failed, regressing destination now.

Looks like I lucked out! So I'm just going to let it run now and see
what happens.

> Your original concern was that this was taking forever (12+ hours and
> counting).  For what it is worth, my experience is that regressions do take
> many hours (depending on size of your current mirror), and they leave you
> wondering if anything is actually happening.
>
> It seems like 296 GB would take me 4-8 hours to regress (I can't really
> remember -- it's been a while).  If your backup is 527 GB (i.e., that's what
> shows up for 'MirrorFileSize' in your session_statistics.* files), then yes,
> I imagine that would take quite some time to regress.  There are probably
> other factors besides size that affect the speed -- disk speed, processor
> speed, load, etc.  I don't know if rdiff-backup logging verbosity is a
> factor or not -- I would think that it might be a factor.

Thanks. It's really good to know the time wasn't out of line.

Some sort of diagnostic messages, especially with -v9, would be really
helpful to know that it's working!

> None of the above addresses your problem with "No space left on device".  I
> would try to restore your repository to a consistent state before
> investigating that further.  (Of course, the real frustrating thing is that
> if the backup fails again, you are forced to wait many hours while you
> repeat the regression of the failed backup.)

Agreed. But considering at this point I haven't even been able to
regress the backups, I'm willing to cross that bridge when I come to
it. There was some weirdness with my box that day, including gnome
crashing, so maybe it just got into a weird state. Even if it fails
again I'm no worse off than I am now.

> <snip>
>
> > On Mon, Sep 09, 2019 at 08:17:04PM -0400, Walt Mankowski wrote:
> > > I ran
> > >
> > >    $ sudo rdiff-backup -v9 --print-statistics --exclude-filelist /usr/local/etc/rdiff_exclude / /backup/scruffy 2>&1 | tee rdiff-backup.txt
> > >
> > > This time it exited right away. I've attached the log file, where the
> > > key message is
> > >
> > >    Fatal Error: It appears that a previous rdiff-backup session with
> > >    process id 4351 is still running.
> > >
> > > Process 4351 is /lib/systemd/systemd-resolved
> > >
>
> It would seem that you had a bit of bad luck in that a process ID that had
> been used for a crashed rdiff-backup session happened to now be in use again
> for an unrelated process (systemd-resolved).

That is bizarre! Especially because it was a systemd process with a
lowish PID, I figured it had been running since boot.

> > > Is it safe to rerun it with --force?
> > >
>
> Using --force would have gotten around the Fatal Error, but it would have
> also forced other things to happen that you may not want.  In this instance,
> I would have probably restarted systemd-resolved so that it used a different
> PID.  That should have gotten rdiff-backup past that particular error.

Good to know.

> > > > > The latter was when I killed it when I woke up and saw that both of
> > > > > them were running.
> > > > >
>
> That's interesting.  That points out that rdiff-backup does not check if a
> regression is already in progress before starting another one.  That needs
> fixing.
>
> --Joe

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Walt Mankowski
Update -- it took about 30 hours to do the regression, started doing
the backup, and then quickly crashed with another "No space left on
device" exception. In kern.log I found these messages:

Sep 11 21:53:47 scruffy kernel: [294433.260536] EXT4-fs warning (device sde1): ext4_dx_add_entry:2190: Directory (ino: 30017692) index full, reach max htree level :2
Sep 11 21:53:47 scruffy kernel: [294433.260540] EXT4-fs warning (device sde1): ext4_dx_add_entry:2194: Large directory feature is not enabled on this filesystem

It got the error while trying to write a file in
~/.cache/chromium/Default/Cache. Turns out that after running
rdiff-backup for years I'd accumulated over 6 million files in
/backup/scruffy/rdiff-backup-data/increments/home/waltman/.cache/chromium/Default/Cache
It's a bit fuzzy how many files you can add to an ext4 directory, but
it looks like I hit the limit.

I added ~/.cache/chromium to my exclude list and restarted the
backup. It looks a lot happier now.

Walt

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Patrik Dufresne-2
Hello Walt,

That's a good news you manage to recover your backup.

ext4 has limitation that might be reached for a backup storage. Personally,
I would way ext4 file system is not a good choice for data storage. As you
found, it has limitation on number of subfolder, it's a journaling
filesystem, doesn't have copy on write, not snapshot, it doesn't have any
checksum either.

--
Patrik Dufresne Service Logiciel inc.
http://www.patrikdufresne.com <http://patrikdufresne.com/>/
514-971-6442
130 rue Doris
St-Colomban, QC J5K 1T9


On Thu, Sep 12, 2019 at 7:53 AM Walt Mankowski <[hidden email]> wrote:

> Update -- it took about 30 hours to do the regression, started doing
> the backup, and then quickly crashed with another "No space left on
> device" exception. In kern.log I found these messages:
>
> Sep 11 21:53:47 scruffy kernel: [294433.260536] EXT4-fs warning (device
> sde1): ext4_dx_add_entry:2190: Directory (ino: 30017692) index full, reach
> max htree level :2
> Sep 11 21:53:47 scruffy kernel: [294433.260540] EXT4-fs warning (device
> sde1): ext4_dx_add_entry:2194: Large directory feature is not enabled on
> this filesystem
>
> It got the error while trying to write a file in
> ~/.cache/chromium/Default/Cache. Turns out that after running
> rdiff-backup for years I'd accumulated over 6 million files in
>
> /backup/scruffy/rdiff-backup-data/increments/home/waltman/.cache/chromium/Default/Cache
> It's a bit fuzzy how many files you can add to an ext4 directory, but
> it looks like I hit the limit.
>
> I added ~/.cache/chromium to my exclude list and restarted the
> backup. It looks a lot happier now.
>
> Walt
>
> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL:
> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Harald Hannelius


What would You recommend instead?

On Thu, 12 Sep 2019, Patrik Dufresne wrote:

> Hello Walt,
>
> That's a good news you manage to recover your backup.
>
> ext4 has limitation that might be reached for a backup storage. Personally,
> I would way ext4 file system is not a good choice for data storage. As you
> found, it has limitation on number of subfolder, it's a journaling
> filesystem, doesn't have copy on write, not snapshot, it doesn't have any
> checksum either.
>
> --
> Patrik Dufresne Service Logiciel inc.
> http://www.patrikdufresne.com <http://patrikdufresne.com/>/
> 514-971-6442
> 130 rue Doris
> St-Colomban, QC J5K 1T9
>
>
> On Thu, Sep 12, 2019 at 7:53 AM Walt Mankowski <[hidden email]> wrote:
>
>> Update -- it took about 30 hours to do the regression, started doing
>> the backup, and then quickly crashed with another "No space left on
>> device" exception. In kern.log I found these messages:
>>
>> Sep 11 21:53:47 scruffy kernel: [294433.260536] EXT4-fs warning (device
>> sde1): ext4_dx_add_entry:2190: Directory (ino: 30017692) index full, reach
>> max htree level :2
>> Sep 11 21:53:47 scruffy kernel: [294433.260540] EXT4-fs warning (device
>> sde1): ext4_dx_add_entry:2194: Large directory feature is not enabled on
>> this filesystem
>>
>> It got the error while trying to write a file in
>> ~/.cache/chromium/Default/Cache. Turns out that after running
>> rdiff-backup for years I'd accumulated over 6 million files in
>>
>> /backup/scruffy/rdiff-backup-data/increments/home/waltman/.cache/chromium/Default/Cache
>> It's a bit fuzzy how many files you can add to an ext4 directory, but
>> it looks like I hit the limit.
>>
>> I added ~/.cache/chromium to my exclude list and restarted the
>> backup. It looks a lot happier now.
>>
>> Walt
>>
>> _______________________________________________
>> rdiff-backup-users mailing list at [hidden email]
>> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
>> Wiki URL:
>> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> _______________________________________________
> rdiff-backup-users mailing list at [hidden email]
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
>
>

--

Harald Hannelius | harald.hannelius/a\arcada.fi | +358 50 594 1020

_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Patrik Dufresne-2
For a server, I would recommend ZFS without hesitation. Data integrity is
at the heart of ZFS which makes it a very good choice for backup storage.
It provides many features that ease the storage management. Quota,
compression, configurable record size, configurable sync writes, raidz,
snapshots, etc.


For an external storage, like a USB drive, I would probably pick BTRFS for
interchangeability reason. ZFS might still be used for an external drive,
but required the installation of ZFS on Linux to be working which is not
installed by default. While BTRFS is shipped as part of Linux Kernel. So in
case of emergency, you might plug the disk in almost any Linux computer and
get access to your files. BTRFS provide checksum and copy on write feature
that you want to ensure data integrity. But I would not recommend BTRFS for
any RAID setup. RAID5/6 is known to be buggy for a couple of years. I would
not trust my data on a BTRFS RAID. But for a single drive it's a very good
alternative to ext4

--
Patrik Dufresne Service Logiciel inc.
http://www.patrikdufresne.com <http://patrikdufresne.com/>/
514-971-6442
130 rue Doris
St-Colomban, QC J5K 1T9


On Thu, Sep 12, 2019 at 8:38 AM Harald Hannelius <[hidden email]>
wrote:

>
>
> What would You recommend instead?
>
> On Thu, 12 Sep 2019, Patrik Dufresne wrote:
>
> > Hello Walt,
> >
> > That's a good news you manage to recover your backup.
> >
> > ext4 has limitation that might be reached for a backup storage.
> Personally,
> > I would way ext4 file system is not a good choice for data storage. As
> you
> > found, it has limitation on number of subfolder, it's a journaling
> > filesystem, doesn't have copy on write, not snapshot, it doesn't have any
> > checksum either.
> >
> > --
> > Patrik Dufresne Service Logiciel inc.
> > http://www.patrikdufresne.com <http://patrikdufresne.com/>/
> > 514-971-6442
> > 130 rue Doris
> > St-Colomban, QC J5K 1T9
> >
> >
> > On Thu, Sep 12, 2019 at 7:53 AM Walt Mankowski <[hidden email]>
> wrote:
> >
> >> Update -- it took about 30 hours to do the regression, started doing
> >> the backup, and then quickly crashed with another "No space left on
> >> device" exception. In kern.log I found these messages:
> >>
> >> Sep 11 21:53:47 scruffy kernel: [294433.260536] EXT4-fs warning (device
> >> sde1): ext4_dx_add_entry:2190: Directory (ino: 30017692) index full,
> reach
> >> max htree level :2
> >> Sep 11 21:53:47 scruffy kernel: [294433.260540] EXT4-fs warning (device
> >> sde1): ext4_dx_add_entry:2194: Large directory feature is not enabled on
> >> this filesystem
> >>
> >> It got the error while trying to write a file in
> >> ~/.cache/chromium/Default/Cache. Turns out that after running
> >> rdiff-backup for years I'd accumulated over 6 million files in
> >>
> >>
> /backup/scruffy/rdiff-backup-data/increments/home/waltman/.cache/chromium/Default/Cache
> >> It's a bit fuzzy how many files you can add to an ext4 directory, but
> >> it looks like I hit the limit.
> >>
> >> I added ~/.cache/chromium to my exclude list and restarted the
> >> backup. It looks a lot happier now.
> >>
> >> Walt
> >>
> >> _______________________________________________
> >> rdiff-backup-users mailing list at [hidden email]
> >> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> >> Wiki URL:
> >> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> > _______________________________________________
> > rdiff-backup-users mailing list at [hidden email]
> > https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> > Wiki URL:
> http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
> >
> >
>
> --
>
> Harald Hannelius | harald.hannelius/a\arcada.fi | +358 50 594 1020
>
_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
Reply | Threaded
Open this post in threaded view
|

Re: --check-destination-dir taking a very long time

Robert Nichols-2
On 9/12/19 7:55 AM, Patrik Dufresne wrote:

> For a server, I would recommend ZFS without hesitation. Data integrity is
> at the heart of ZFS which makes it a very good choice for backup storage.
> It provides many features that ease the storage management. Quota,
> compression, configurable record size, configurable sync writes, raidz,
> snapshots, etc.
>
>
> For an external storage, like a USB drive, I would probably pick BTRFS for
> interchangeability reason. ZFS might still be used for an external drive,
> but required the installation of ZFS on Linux to be working which is not
> installed by default. While BTRFS is shipped as part of Linux Kernel. So in
> case of emergency, you might plug the disk in almost any Linux computer and
> get access to your files. BTRFS provide checksum and copy on write feature
> that you want to ensure data integrity. But I would not recommend BTRFS for
> any RAID setup. RAID5/6 is known to be buggy for a couple of years. I would
> not trust my data on a BTRFS RAID. But for a single drive it's a very good
> alternative to ext4

Note that BTRFS is no longer supported in RHEL 8. "You can no longer create, mount, or install on Btrfs file systems in Red Hat Enterprise Linux 8." (Quoted from https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux/8/html-single/considerations_in_adopting_rhel_8/)

--
Bob Nichols     "NOSPAM" is really part of my email address.
                 Do NOT delete it.


_______________________________________________
rdiff-backup-users mailing list at [hidden email]
https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
12