[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [rdiff-backup-users] --check-destination-dir taking a very long time
From: |
Walt Mankowski |
Subject: |
Re: [rdiff-backup-users] --check-destination-dir taking a very long time |
Date: |
Tue, 10 Sep 2019 09:31:00 -0400 |
User-agent: |
Mutt/1.10.1 (2018-07-13) |
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 <address@hidden> 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 <address@hidden>
> >>> 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, <address@hidden>
> >>> 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, <
> >>> address@hidden>
> >>>>>> 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
> >>> address@hidden
> >>>>>>>>>> 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 address@hidden
> >>>>>>>> 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 address@hidden
> >>>>>> 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 address@hidden
> https://lists.nongnu.org/mailman/listinfo/rdiff-backup-users
> Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, (continued)
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Patrik Dufresne, 2019/09/09
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Walt Mankowski, 2019/09/09
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Patrik Dufresne, 2019/09/09
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Walt Mankowski, 2019/09/09
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Patrik Dufresne, 2019/09/09
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Walt Mankowski, 2019/09/09
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Walt Mankowski, 2019/09/09
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Dominic Raferd, 2019/09/10
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Walt Mankowski, 2019/09/10
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Ilario Gelmetti, 2019/09/10
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time,
Walt Mankowski <=
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Eric Lavarde, 2019/09/10
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Joe Steele, 2019/09/10
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Walt Mankowski, 2019/09/10
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Walt Mankowski, 2019/09/12
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Patrik Dufresne, 2019/09/12
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Harald Hannelius, 2019/09/12
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Patrik Dufresne, 2019/09/12
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Robert Nichols, 2019/09/12
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Walt Mankowski, 2019/09/12
- Re: [rdiff-backup-users] --check-destination-dir taking a very long time, Patrik Dufresne, 2019/09/12