Re: [rdiff-backup-users] --check-destination-dir taking a very long time

[Ilario Gelmetti]

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

signature.asc
Description: OpenPGP digital signature