Exception ... assert not incrp.lstat()

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

Exception ... assert not incrp.lstat()

Michael Born
Dear rdiff-backup users.

After years of trouble-free rdiff-backup usage I have a big problem with
a weekly backup I started some months ago.
My OpenSUSE 13.2 64bit /home/user (ext4) has been successfully backuped
to my USB3 hdd (ext4) with enough free space on it.

Since after the 11th incremental backup I get this Exception:

Fri Aug 19 19:21:05 2016  Exception 'Path:
/run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/long_filename_data/1.2016-07-30T16:25:41+02:00.diff.gz
Index: ('long_filename_data', '1.2016-07-30T16:25:41+02:00.diff.gz')
Data: {'acl': <rdiff_backup.eas_acls.AccessControlLists instance at
0x7eff65474050>, 'uid': 1000, 'perms': 420, 'type': 'reg', 'gname':
'users', 'ea': <rdiff_backup.eas_acls.ExtendedAttributes instance at
0x7eff65464ea8>, 'ctime': 1470554687, 'devloc': 65025L, 'uname':
'miborn', 'nlink': 1, 'gid': 100, 'mtime': 1469825388, 'atime':
1471028717, 'inode': 58597284, 'size': 62}' raised of class '<type
'exceptions.AssertionError'>':
  File "/usr/lib64/python2.7/site-packages/rdiff_backup/robust.py", line
32, in check_common_error
    try: return function(*args)
  File "/usr/lib64/python2.7/site-packages/rdiff_backup/increment.py",
line 43, in Increment
    incrp = makediff(new, mirror, incpref)
  File "/usr/lib64/python2.7/site-packages/rdiff_backup/increment.py",
line 79, in makediff
    if compress: diff = get_inc(incpref, "diff.gz")
  File "/usr/lib64/python2.7/site-packages/rdiff_backup/increment.py",
line 123, in get_inc
    assert not incrp.lstat(), incrp

(more output here: http://pastebin.com/czKdWATg )

The following doesn't work any more after the Exception.
miborn@hnb533:~> rdiff-backup --list-increments -v9
...
Fri Aug 19 23:37:23 2016  Fatal Error: Previous backup to
/run/media/miborn/WD1TB/T450s_rdiff-backup seems to have failed.
Rerun rdiff-backup with --check-destination-dir option to revert
directory to state before unsuccessful session.

After running the --check-destination-dir command I can list the backups
(see here: http://pastebin.com/zcZq6Sbh ), but re-running (incrementing)
the backup only runs in the Exception again.

Could anybody help debugging that problem?
Is this problem known and does a solution exist?

For testing I did the following things.
1. I created a new backup (new/empty destination dir). There, the backup
finished without an error.

2. I removed the last incremental backup with the help of that script:
http://www.timedicer.co.uk/programs/help/rdiff-backup-regress.sh.php
But, the incremental backup did run into the same Exception again.

3. I used the option --exclude
/home/miborn/.kde4/share/apps/okular/docdata/ to exclude the file where
the Exception happened before. Unfortunately rdiff-backup presented me a
new error message:
File "/usr/lib64/python2.7/gzip.py", line 432, in seek
    raise IOError('Negative seek in write mode')
(longer message see here: http://pastebin.com/G64SrnVn )

4. I checked the access rights of the .xml file that was listed before
the exception and also the .diff.gz file of the backup. All rights seem
all right to me. The backup is always run as the user and the user has
write access to the USB disk.


Cheers,
Michael

PS: my command line is:
time rdiff-backup -v9 --exclude
/home/miborn/.kde4/share/apps/okular/docdata/ --exclude
/home/miborn/.cache --exclude /home/miborn/MediathekView/ --exclude
/home/miborn/mnt --exclude /home/miborn/yEd --exclude /home/miborn/mnt2
--exclude /home/miborn/Videos --exclude /home/miborn/.local/share/Trash/
--exclude /home/miborn/.local/share/Steam /home/miborn
/run/media/miborn/WD1TB/T450s_rdiff-backup


_______________________________________________
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: Exception ... assert not incrp.lstat()

Joe Steele-2
This is a bug.  I was able to reproduce it and have created an issue for
it here:

https://github.com/sol1/rdiff-backup/issues/9

You can try to work around your problem by:

1) using '--check-destination-dir'; then

2) look at the name of your current_mirror file (and there must only be
one of them).  In your case, it looks like that name would be:

/run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/current_mirror.2016-07-21T22:41:21+02:00.data

3) look in 'rdiff-backup-data/long_filename_data/' and remove (but keep
somewhere safe, just in case) any files there that have a date in their
filename that is greater or equal to the date in the current_mirror
filename.  In your case, it looks like there will at least be:

/run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/long_filename_data/1.2016-07-30T16:25:41+02:00.diff.gz

That *should* fix things for you, but I give no guarantees.

I am a little puzzled about why the date of the file in the
long_filename_data/ directory is greater than (instead of equal to) the
date of your current_mirror (after having regressed the repository).  I
guess that would be possible if you regressed your repository backward
more than just a single increment.


On 8/20/2016 7:13 AM, Michael Born wrote:

> Dear rdiff-backup users.
>
> After years of trouble-free rdiff-backup usage I have a big problem with
> a weekly backup I started some months ago.
> My OpenSUSE 13.2 64bit /home/user (ext4) has been successfully backuped
> to my USB3 hdd (ext4) with enough free space on it.
>
> Since after the 11th incremental backup I get this Exception:
>
> Fri Aug 19 19:21:05 2016  Exception 'Path:
> /run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/long_filename_data/1.2016-07-30T16:25:41+02:00.diff.gz
> Index: ('long_filename_data', '1.2016-07-30T16:25:41+02:00.diff.gz')
> Data: {'acl': <rdiff_backup.eas_acls.AccessControlLists instance at
> 0x7eff65474050>, 'uid': 1000, 'perms': 420, 'type': 'reg', 'gname':
> 'users', 'ea': <rdiff_backup.eas_acls.ExtendedAttributes instance at
> 0x7eff65464ea8>, 'ctime': 1470554687, 'devloc': 65025L, 'uname':
> 'miborn', 'nlink': 1, 'gid': 100, 'mtime': 1469825388, 'atime':
> 1471028717, 'inode': 58597284, 'size': 62}' raised of class '<type
> 'exceptions.AssertionError'>':
>   File "/usr/lib64/python2.7/site-packages/rdiff_backup/robust.py", line
> 32, in check_common_error
>     try: return function(*args)
>   File "/usr/lib64/python2.7/site-packages/rdiff_backup/increment.py",
> line 43, in Increment
>     incrp = makediff(new, mirror, incpref)
>   File "/usr/lib64/python2.7/site-packages/rdiff_backup/increment.py",
> line 79, in makediff
>     if compress: diff = get_inc(incpref, "diff.gz")
>   File "/usr/lib64/python2.7/site-packages/rdiff_backup/increment.py",
> line 123, in get_inc
>     assert not incrp.lstat(), incrp
>
> (more output here: http://pastebin.com/czKdWATg )
>
> The following doesn't work any more after the Exception.
> miborn@hnb533:~> rdiff-backup --list-increments -v9
> ...
> Fri Aug 19 23:37:23 2016  Fatal Error: Previous backup to
> /run/media/miborn/WD1TB/T450s_rdiff-backup seems to have failed.
> Rerun rdiff-backup with --check-destination-dir option to revert
> directory to state before unsuccessful session.
>
> After running the --check-destination-dir command I can list the backups
> (see here: http://pastebin.com/zcZq6Sbh ), but re-running (incrementing)
> the backup only runs in the Exception again.
>
> Could anybody help debugging that problem?
> Is this problem known and does a solution exist?
>
> For testing I did the following things.
> 1. I created a new backup (new/empty destination dir). There, the backup
> finished without an error.
>
> 2. I removed the last incremental backup with the help of that script:
> http://www.timedicer.co.uk/programs/help/rdiff-backup-regress.sh.php
> But, the incremental backup did run into the same Exception again.
>
> 3. I used the option --exclude
> /home/miborn/.kde4/share/apps/okular/docdata/ to exclude the file where
> the Exception happened before. Unfortunately rdiff-backup presented me a
> new error message:
> File "/usr/lib64/python2.7/gzip.py", line 432, in seek
>     raise IOError('Negative seek in write mode')
> (longer message see here: http://pastebin.com/G64SrnVn )
>
> 4. I checked the access rights of the .xml file that was listed before
> the exception and also the .diff.gz file of the backup. All rights seem
> all right to me. The backup is always run as the user and the user has
> write access to the USB disk.
>
>
> Cheers,
> Michael
>
> PS: my command line is:
> time rdiff-backup -v9 --exclude
> /home/miborn/.kde4/share/apps/okular/docdata/ --exclude
> /home/miborn/.cache --exclude /home/miborn/MediathekView/ --exclude
> /home/miborn/mnt --exclude /home/miborn/yEd --exclude /home/miborn/mnt2
> --exclude /home/miborn/Videos --exclude /home/miborn/.local/share/Trash/
> --exclude /home/miborn/.local/share/Steam /home/miborn
> /run/media/miborn/WD1TB/T450s_rdiff-backup
>
>
> _______________________________________________
> 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: Exception ... assert not incrp.lstat()

Michael Born
Wow, that was a fast response.



Am 21.08.2016 um 04:37 schrieb Joe Steele:
> This is a bug.  I was able to reproduce it and have created an issue for
> it here:
>
> https://github.com/sol1/rdiff-backup/issues/9
>
> You can try to work around your problem by:
>
> 1) using '--check-destination-dir'; then
That one failed 'Too many recent increments'
( http://pastebin.com/vXnmrMug )

> 2) look at the name of your current_mirror file (and there must only be
> one of them).  In your case, it looks like that name would be:
>
> /run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/current_mirror.2016-07-21T22:41:21+02:00.data

After removing current_mirror.2016-08-21T22:07:29+02:00.data I can again
--list-increments
( *this output is from todays try* http://pastebin.com/V0bKu3LV )

>
> 3) look in 'rdiff-backup-data/long_filename_data/' and remove (but keep
> somewhere safe, just in case) any files there that have a date in their
> filename that is greater or equal to the date in the current_mirror
> filename.  In your case, it looks like there will at least be:
>
> /run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/long_filename_data/1.2016-07-30T16:25:41+02:00.diff.gz
I did remove that file yesterday but it didn't fix the problem.
Running my backup gave me immediately this error:
http://pastebin.com/qLtRe861

I tried the steps 1-3 again today. This time there was no
1.2016-07-30T16:25:41+02:00.diff.gz file to remove in long_filename_data/
But a new current_mirror.2016-08-21T22:07:29+02:00.data file had to be
removed.
The result was the same. I could run the --list-increments option
successfully, but the backup failed with the exception.

Do you have more suggestions what I could try?

Thank you.
Michael

>
> That *should* fix things for you, but I give no guarantees.
>
> I am a little puzzled about why the date of the file in the
> long_filename_data/ directory is greater than (instead of equal to) the
> date of your current_mirror (after having regressed the repository).  I
> guess that would be possible if you regressed your repository backward
> more than just a single increment.
>
>
> On 8/20/2016 7:13 AM, Michael Born wrote:
>> Dear rdiff-backup users.
>>
>> After years of trouble-free rdiff-backup usage I have a big problem with
>> a weekly backup I started some months ago.
>> My OpenSUSE 13.2 64bit /home/user (ext4) has been successfully backuped
>> to my USB3 hdd (ext4) with enough free space on it.
>>
>> Since after the 11th incremental backup I get this Exception:
>>
>> Fri Aug 19 19:21:05 2016  Exception 'Path:
>> /run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/long_filename_data/1.2016-07-30T16:25:41+02:00.diff.gz
>>
>> Index: ('long_filename_data', '1.2016-07-30T16:25:41+02:00.diff.gz')
>> Data: {'acl': <rdiff_backup.eas_acls.AccessControlLists instance at
>> 0x7eff65474050>, 'uid': 1000, 'perms': 420, 'type': 'reg', 'gname':
>> 'users', 'ea': <rdiff_backup.eas_acls.ExtendedAttributes instance at
>> 0x7eff65464ea8>, 'ctime': 1470554687, 'devloc': 65025L, 'uname':
>> 'miborn', 'nlink': 1, 'gid': 100, 'mtime': 1469825388, 'atime':
>> 1471028717, 'inode': 58597284, 'size': 62}' raised of class '<type
>> 'exceptions.AssertionError'>':
>>   File "/usr/lib64/python2.7/site-packages/rdiff_backup/robust.py", line
>> 32, in check_common_error
>>     try: return function(*args)
>>   File "/usr/lib64/python2.7/site-packages/rdiff_backup/increment.py",
>> line 43, in Increment
>>     incrp = makediff(new, mirror, incpref)
>>   File "/usr/lib64/python2.7/site-packages/rdiff_backup/increment.py",
>> line 79, in makediff
>>     if compress: diff = get_inc(incpref, "diff.gz")
>>   File "/usr/lib64/python2.7/site-packages/rdiff_backup/increment.py",
>> line 123, in get_inc
>>     assert not incrp.lstat(), incrp
>>
>> (more output here: http://pastebin.com/czKdWATg )
>>
>> The following doesn't work any more after the Exception.
>> miborn@hnb533:~> rdiff-backup --list-increments -v9
>> ...
>> Fri Aug 19 23:37:23 2016  Fatal Error: Previous backup to
>> /run/media/miborn/WD1TB/T450s_rdiff-backup seems to have failed.
>> Rerun rdiff-backup with --check-destination-dir option to revert
>> directory to state before unsuccessful session.
>>
>> After running the --check-destination-dir command I can list the backups
>> (see here: http://pastebin.com/zcZq6Sbh ), but re-running (incrementing)
>> the backup only runs in the Exception again.
>>
>> Could anybody help debugging that problem?
>> Is this problem known and does a solution exist?
>>
>> For testing I did the following things.
>> 1. I created a new backup (new/empty destination dir). There, the backup
>> finished without an error.
>>
>> 2. I removed the last incremental backup with the help of that script:
>> http://www.timedicer.co.uk/programs/help/rdiff-backup-regress.sh.php
>> But, the incremental backup did run into the same Exception again.
>>
>> 3. I used the option --exclude
>> /home/miborn/.kde4/share/apps/okular/docdata/ to exclude the file where
>> the Exception happened before. Unfortunately rdiff-backup presented me a
>> new error message:
>> File "/usr/lib64/python2.7/gzip.py", line 432, in seek
>>     raise IOError('Negative seek in write mode')
>> (longer message see here: http://pastebin.com/G64SrnVn )
>>
>> 4. I checked the access rights of the .xml file that was listed before
>> the exception and also the .diff.gz file of the backup. All rights seem
>> all right to me. The backup is always run as the user and the user has
>> write access to the USB disk.
>>
>>
>> Cheers,
>> Michael
>>
>> PS: my command line is:
>> time rdiff-backup -v9 --exclude
>> /home/miborn/.kde4/share/apps/okular/docdata/ --exclude
>> /home/miborn/.cache --exclude /home/miborn/MediathekView/ --exclude
>> /home/miborn/mnt --exclude /home/miborn/yEd --exclude /home/miborn/mnt2
>> --exclude /home/miborn/Videos --exclude /home/miborn/.local/share/Trash/
>> --exclude /home/miborn/.local/share/Steam /home/miborn
>> /run/media/miborn/WD1TB/T450s_rdiff-backup
>>
>>
>> _______________________________________________
>> 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: Exception ... assert not incrp.lstat()

Joe Steele-2
On 8/22/2016 4:21 PM, Michael Born wrote:

> Wow, that was a fast response.
>
>
>
> Am 21.08.2016 um 04:37 schrieb Joe Steele:
>> This is a bug.  I was able to reproduce it and have created an issue for
>> it here:
>>
>> https://github.com/sol1/rdiff-backup/issues/9
>>
>> You can try to work around your problem by:
>>
>> 1) using '--check-destination-dir'; then
> That one failed 'Too many recent increments'
> ( http://pastebin.com/vXnmrMug )

'Too many recent increments' -- that shouldn't happen.  I know of a way
to reproduce such an error, but it involves indiscriminate juggling of
current_mirror files (that's a little foreshadowing).

>
>> 2) look at the name of your current_mirror file (and there must only be
>> one of them).  In your case, it looks like that name would be:
>>
>> /run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/current_mirror.2016-07-21T22:41:21+02:00.data
>
> After removing current_mirror.2016-08-21T22:07:29+02:00.data I can again
> --list-increments
> ( *this output is from todays try* http://pastebin.com/V0bKu3LV )
>

Hold on.  It is never appropriate to remove current_mirror files
manually.  Maybe I wasn't being clear about "there must only be one of
them".  I certainly didn't mean for you to manually remove any
current_mirror files.

Normally there is only one current_mirror file.  But when rdiff-backup
starts, it creates a new current_mirror file and leaves the old file in
place.  If the backup completes successfully, then the old file is
removed.  But if there is an error, rdiff-backup quits, leaving you with
2 current_mirror files.  Subsequent runs of rdiff-backup will then
complain that the last backup failed and that you should use
"--check-destination-dir" to fix the problem.  Running "rdiff-backup
--check-destination-dir" cleans up the repository after the last failed
backup and then removes the second (i.e., more recent) current_mirror
file so there is only one current_mirror file again. That process is the
*only* way that should be used to remove a second current_mirror file.

Regarding your log immediately above -- It shows:

|     increments.2016-07-21T22:41:21+02:00.dir   Thu Jul 21 22:41:21 2016
| Current mirror: Thu Jul 21 22:41:21 2016

That is showing that your last increment has the same date/time
(2016-07-21T22:41:21) as your current_mirror file.  That's messed up.
The current mirror should be later than the last increment.  But I guess
that makes sense, knowing that you deleted a second current mirror file
with a later date.

>>
>> 3) look in 'rdiff-backup-data/long_filename_data/' and remove (but keep
>> somewhere safe, just in case) any files there that have a date in their
>> filename that is greater or equal to the date in the current_mirror
>> filename.  In your case, it looks like there will at least be:
>>
>> /run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/long_filename_data/1.2016-07-30T16:25:41+02:00.diff.gz
> I did remove that file yesterday but it didn't fix the problem.
> Running my backup gave me immediately this error:
> http://pastebin.com/qLtRe861
>
> I tried the steps 1-3 again today. This time there was no
> 1.2016-07-30T16:25:41+02:00.diff.gz file to remove in long_filename_data/
> But a new current_mirror.2016-08-21T22:07:29+02:00.data file had to be
> removed.

No!  Don't remove current_mirror files!

> The result was the same. I could run the --list-increments option
> successfully, but the backup failed with the exception.
>
> Do you have more suggestions what I could try?
>
> Thank you.
> Michael
>
>>
>> That *should* fix things for you, but I give no guarantees.
>>
>> I am a little puzzled about why the date of the file in the
>> long_filename_data/ directory is greater than (instead of equal to) the
>> date of your current_mirror (after having regressed the repository).  I
>> guess that would be possible if you regressed your repository backward
>> more than just a single increment.
>>
>>
>> On 8/20/2016 7:13 AM, Michael Born wrote:
>>> Dear rdiff-backup users.
>>>

<snip>

>>>
>>> 3. I used the option --exclude
>>> /home/miborn/.kde4/share/apps/okular/docdata/ to exclude the file where
>>> the Exception happened before. Unfortunately rdiff-backup presented me a
>>> new error message:
>>> File "/usr/lib64/python2.7/gzip.py", line 432, in seek
>>>     raise IOError('Negative seek in write mode')
>>> (longer message see here: http://pastebin.com/G64SrnVn )
>>>

Unfortunately, I didn't read your first message carefully enough to
notice the above error until now.  It seems you are using a buggy
version of rdiff-backup created by openSUSE.  The line numbers in the
above log indicates that your version of rdiff-backup was patched with
this unofficial patch:

https://build.opensuse.org/package/view_file/openSUSE:Factory/rdiff-backup/rdiff-backup-1.2.8-sparsefiles.diff?expand=1

But you do not have this patch which fixes a bug in the above patch:

https://build.opensuse.org/package/view_file/openSUSE:Factory/rdiff-backup/rdiff-backup-1.2.8-sparse-no-seek-in-gzip.diff?expand=1

I don't know much about openSUSE, but this rpm seems to have both patches:

http://download.opensuse.org/repositories/Archiving/openSUSE_13.2/x86_64/rdiff-backup-1.2.8-42.5.x86_64.rpm

It's likely that your problems may have all started with a "Negative
seek in write mode" error (similar to that contained in your log above,
and fixed by the second patch above).  That error caused rdiff-backup to
fail.  You then were unfortunate enough to encounter another bug
(https://github.com/sol1/rdiff-backup/issues/9) that prevented
"--check-destination-dir" from working because your backup contained
file(s) with unusually long names.

The first thing to do would be to get a version of rdiff-backup from
openSUSE that is fully patched.

Next -- well, I'm not sure what's next.  You have attempted backups,
used an rdiff-backup-regress script, removed current_mirror files, and
attempted more backups.  Sorting that out might be tricky.  A listing of
the files & folders contained in your rdiff-backup-data/ directory might
help as a first step to see what the different dates in the filenames show.

_______________________________________________
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: Exception ... assert not incrp.lstat()

Michael Born
I checked my rdiff-backup (version 1.2.8-22.1.4) which was from my main
repository.
I now switched to the official Archiving repository and got the version
1.2.8-42.5
I have to admit that I can't see what patches are in what version (your
linked rdiff-backup-1.2.8-sparse-no-seek-in-gzip.diff shows a Date:
2016-06-29 but in the overview they say it was changed about 2 years ago).

I'm fine with my messed up backup. I already created a new one and don't
rely on the old one.

But what happens with the bug you identified? Will that one be
officially fixed? Should I file a bug report somewhere? (Your github
issue has all in it already)

For my own backup. Should I exclude my long name file from the backup
for now?

Thank you.
Michael

Am 23.08.2016 um 03:58 schrieb Joe Steele:

> On 8/22/2016 4:21 PM, Michael Born wrote:
>> Wow, that was a fast response.
>>
>>
>>
>> Am 21.08.2016 um 04:37 schrieb Joe Steele:
>>> This is a bug.  I was able to reproduce it and have created an issue for
>>> it here:
>>>
>>> https://github.com/sol1/rdiff-backup/issues/9
>>>
>>> You can try to work around your problem by:
>>>
>>> 1) using '--check-destination-dir'; then
>> That one failed 'Too many recent increments'
>> ( http://pastebin.com/vXnmrMug )
>
> 'Too many recent increments' -- that shouldn't happen.  I know of a way
> to reproduce such an error, but it involves indiscriminate juggling of
> current_mirror files (that's a little foreshadowing).
>
>>
>>> 2) look at the name of your current_mirror file (and there must only be
>>> one of them).  In your case, it looks like that name would be:
>>>
>>> /run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/current_mirror.2016-07-21T22:41:21+02:00.data
>>>
>>
>> After removing current_mirror.2016-08-21T22:07:29+02:00.data I can again
>> --list-increments
>> ( *this output is from todays try* http://pastebin.com/V0bKu3LV )
>>
>
> Hold on.  It is never appropriate to remove current_mirror files
> manually.  Maybe I wasn't being clear about "there must only be one of
> them".  I certainly didn't mean for you to manually remove any
> current_mirror files.
>
> Normally there is only one current_mirror file.  But when rdiff-backup
> starts, it creates a new current_mirror file and leaves the old file in
> place.  If the backup completes successfully, then the old file is
> removed.  But if there is an error, rdiff-backup quits, leaving you with
> 2 current_mirror files.  Subsequent runs of rdiff-backup will then
> complain that the last backup failed and that you should use
> "--check-destination-dir" to fix the problem.  Running "rdiff-backup
> --check-destination-dir" cleans up the repository after the last failed
> backup and then removes the second (i.e., more recent) current_mirror
> file so there is only one current_mirror file again. That process is the
> *only* way that should be used to remove a second current_mirror file.
>
> Regarding your log immediately above -- It shows:
>
> |     increments.2016-07-21T22:41:21+02:00.dir   Thu Jul 21 22:41:21 2016
> | Current mirror: Thu Jul 21 22:41:21 2016
>
> That is showing that your last increment has the same date/time
> (2016-07-21T22:41:21) as your current_mirror file.  That's messed up.
> The current mirror should be later than the last increment.  But I guess
> that makes sense, knowing that you deleted a second current mirror file
> with a later date.
>
>>>
>>> 3) look in 'rdiff-backup-data/long_filename_data/' and remove (but keep
>>> somewhere safe, just in case) any files there that have a date in their
>>> filename that is greater or equal to the date in the current_mirror
>>> filename.  In your case, it looks like there will at least be:
>>>
>>> /run/media/miborn/WD1TB/T450s_rdiff-backup/rdiff-backup-data/long_filename_data/1.2016-07-30T16:25:41+02:00.diff.gz
>>>
>> I did remove that file yesterday but it didn't fix the problem.
>> Running my backup gave me immediately this error:
>> http://pastebin.com/qLtRe861
>>
>> I tried the steps 1-3 again today. This time there was no
>> 1.2016-07-30T16:25:41+02:00.diff.gz file to remove in long_filename_data/
>> But a new current_mirror.2016-08-21T22:07:29+02:00.data file had to be
>> removed.
>
> No!  Don't remove current_mirror files!
>
>> The result was the same. I could run the --list-increments option
>> successfully, but the backup failed with the exception.
>>
>> Do you have more suggestions what I could try?
>>
>> Thank you.
>> Michael
>>
>>>
>>> That *should* fix things for you, but I give no guarantees.
>>>
>>> I am a little puzzled about why the date of the file in the
>>> long_filename_data/ directory is greater than (instead of equal to) the
>>> date of your current_mirror (after having regressed the repository).  I
>>> guess that would be possible if you regressed your repository backward
>>> more than just a single increment.
>>>
>>>
>>> On 8/20/2016 7:13 AM, Michael Born wrote:
>>>> Dear rdiff-backup users.
>>>>
>
> <snip>
>
>>>>
>>>> 3. I used the option --exclude
>>>> /home/miborn/.kde4/share/apps/okular/docdata/ to exclude the file where
>>>> the Exception happened before. Unfortunately rdiff-backup presented
>>>> me a
>>>> new error message:
>>>> File "/usr/lib64/python2.7/gzip.py", line 432, in seek
>>>>     raise IOError('Negative seek in write mode')
>>>> (longer message see here: http://pastebin.com/G64SrnVn )
>>>>
>
> Unfortunately, I didn't read your first message carefully enough to
> notice the above error until now.  It seems you are using a buggy
> version of rdiff-backup created by openSUSE.  The line numbers in the
> above log indicates that your version of rdiff-backup was patched with
> this unofficial patch:
>
> https://build.opensuse.org/package/view_file/openSUSE:Factory/rdiff-backup/rdiff-backup-1.2.8-sparsefiles.diff?expand=1
>
>
> But you do not have this patch which fixes a bug in the above patch:
>
> https://build.opensuse.org/package/view_file/openSUSE:Factory/rdiff-backup/rdiff-backup-1.2.8-sparse-no-seek-in-gzip.diff?expand=1
>
>
> I don't know much about openSUSE, but this rpm seems to have both patches:
>
> http://download.opensuse.org/repositories/Archiving/openSUSE_13.2/x86_64/rdiff-backup-1.2.8-42.5.x86_64.rpm
>
>
> It's likely that your problems may have all started with a "Negative
> seek in write mode" error (similar to that contained in your log above,
> and fixed by the second patch above).  That error caused rdiff-backup to
> fail.  You then were unfortunate enough to encounter another bug
> (https://github.com/sol1/rdiff-backup/issues/9) that prevented
> "--check-destination-dir" from working because your backup contained
> file(s) with unusually long names.
>
> The first thing to do would be to get a version of rdiff-backup from
> openSUSE that is fully patched.
>
> Next -- well, I'm not sure what's next.  You have attempted backups,
> used an rdiff-backup-regress script, removed current_mirror files, and
> attempted more backups.  Sorting that out might be tricky.  A listing of
> the files & folders contained in your rdiff-backup-data/ directory might
> help as a first step to see what the different dates in the filenames show.
>


_______________________________________________
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: Exception ... assert not incrp.lstat()

Joe Steele-2
On 8/23/2016 7:12 AM, Michael Born wrote:
> I checked my rdiff-backup (version 1.2.8-22.1.4) which was from my main
> repository.
> I now switched to the official Archiving repository and got the version
> 1.2.8-42.5
> I have to admit that I can't see what patches are in what version

You'd need to look at the source rpm to see the patches.  I had looked
at the 1.2.8-42.5 rpm and saw that it had the patches.  You could also
look at the installed code (rdiff_backup/rpath.py) and see if it has
been patched.

> (your
> linked rdiff-backup-1.2.8-sparse-no-seek-in-gzip.diff shows a Date:
> 2016-06-29 but in the overview they say it was changed about 2 years ago).
>

I was puzzled about that 2016 date as well.  It must be a typo.

I knew this gzip 'Negative seek in write mode' issue was sounding
strangely familiar:

https://lists.nongnu.org/archive/html/rdiff-backup-users/2015-12/msg00006.html


> I'm fine with my messed up backup. I already created a new one and don't
> rely on the old one.
>
> But what happens with the bug you identified? Will that one be
> officially fixed? Should I file a bug report somewhere? (Your github
> issue has all in it already)
>

Who knows when/if it will be fixed.  That would obviously require
someone with the skills, time, and inclination to volunteer.  Very
serious bugs and and bugs that are simple to fix are likely to be
addressed more quickly (at least unofficially within the distros that
provide the package).

Bugs used to be reported at:

http://savannah.nongnu.org/bugs/?group=rdiff-backup

But then there was an announcement that Sol1 was taking over official
maintainership of rdiff-backup:

https://lists.nongnu.org/archive/html/rdiff-backup-users/2016-02/msg00009.html

That's the main reason I created the issue on github.

Sol1 has also created a simple web page with links to github which I
hadn't seen before today:

http://rdiff-backup.org/

> For my own backup. Should I exclude my long name file from the backup
> for now?
>

It's up to you, but I wouldn't worry about it.  It should only be a
problem when a file with a really long name is created, modified, or
deleted, and then the next backup thereafter happens to have an
unrelated failure.  I'm guessing such combinations are likely to be
rare.  In such cases, you will need to "--check-destination-dir", as
usual, after the failure.  If you then run another backup and it fails
with something like:

...
   File "/usr/lib/python2.3/site-packages/rdiff_backup/increment.py",
line 123, in get_inc
     assert not incrp.lstat(), incrp
AssertionError: Path:
dst/rdiff-backup-data/long_filename_data/1.2016-08-20T21:17:56-04:00.diff.gz

That's your clue that there are file(s) in
rdiff-backup-data/long_filename_data/ that are not being cleaned up.
Rerun "--check-destination-dir", then (assuming that was successful,
meaning you now have just 1 current_mirror file) look in the
rdiff-backup-data/long_filename_data/ directory and move out of the way
any files with a date/time in their names that matches the date/time in
the current_mirror filename.  There might be numerous files, or there
might be just one, in which case the error message is telling you
exactly which one it is.

_______________________________________________
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: Exception ... assert not incrp.lstat()

Michael Born
Thank you very much for your help and explanations.

I will continue using rdiff-backup but without the (unimportant) folder
with the long filename file.

I don't have the skill to fix that bug, but hope that Sol1 takes care.
I will keep my old backup in case it could be useful for
debugging/testing. Please, let me know if I can help.

Cheers,
Michael

Am 23.08.2016 um 21:29 schrieb Joe Steele:

> On 8/23/2016 7:12 AM, Michael Born wrote:
>> I checked my rdiff-backup (version 1.2.8-22.1.4) which was from my main
>> repository.
>> I now switched to the official Archiving repository and got the version
>> 1.2.8-42.5
>> I have to admit that I can't see what patches are in what version
>
> You'd need to look at the source rpm to see the patches.  I had looked
> at the 1.2.8-42.5 rpm and saw that it had the patches.  You could also
> look at the installed code (rdiff_backup/rpath.py) and see if it has
> been patched.
>
>> (your
>> linked rdiff-backup-1.2.8-sparse-no-seek-in-gzip.diff shows a Date:
>> 2016-06-29 but in the overview they say it was changed about 2 years
>> ago).
>>
>
> I was puzzled about that 2016 date as well.  It must be a typo.
>
> I knew this gzip 'Negative seek in write mode' issue was sounding
> strangely familiar:
>
> https://lists.nongnu.org/archive/html/rdiff-backup-users/2015-12/msg00006.html
>
>
>
>> I'm fine with my messed up backup. I already created a new one and don't
>> rely on the old one.
>>
>> But what happens with the bug you identified? Will that one be
>> officially fixed? Should I file a bug report somewhere? (Your github
>> issue has all in it already)
>>
>
> Who knows when/if it will be fixed.  That would obviously require
> someone with the skills, time, and inclination to volunteer.  Very
> serious bugs and and bugs that are simple to fix are likely to be
> addressed more quickly (at least unofficially within the distros that
> provide the package).
>
> Bugs used to be reported at:
>
> http://savannah.nongnu.org/bugs/?group=rdiff-backup
>
> But then there was an announcement that Sol1 was taking over official
> maintainership of rdiff-backup:
>
> https://lists.nongnu.org/archive/html/rdiff-backup-users/2016-02/msg00009.html
>
>
> That's the main reason I created the issue on github.
>
> Sol1 has also created a simple web page with links to github which I
> hadn't seen before today:
>
> http://rdiff-backup.org/
>
>> For my own backup. Should I exclude my long name file from the backup
>> for now?
>>
>
> It's up to you, but I wouldn't worry about it.  It should only be a
> problem when a file with a really long name is created, modified, or
> deleted, and then the next backup thereafter happens to have an
> unrelated failure.  I'm guessing such combinations are likely to be
> rare.  In such cases, you will need to "--check-destination-dir", as
> usual, after the failure.  If you then run another backup and it fails
> with something like:
>
> ...
>   File "/usr/lib/python2.3/site-packages/rdiff_backup/increment.py",
> line 123, in get_inc
>     assert not incrp.lstat(), incrp
> AssertionError: Path:
> dst/rdiff-backup-data/long_filename_data/1.2016-08-20T21:17:56-04:00.diff.gz
>
>
> That's your clue that there are file(s) in
> rdiff-backup-data/long_filename_data/ that are not being cleaned up.
> Rerun "--check-destination-dir", then (assuming that was successful,
> meaning you now have just 1 current_mirror file) look in the
> rdiff-backup-data/long_filename_data/ directory and move out of the way
> any files with a date/time in their names that matches the date/time in
> the current_mirror filename.  There might be numerous files, or there
> might be just one, in which case the error message is telling you
> exactly which one it is.
>


_______________________________________________
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