rdiff-backup-users
[Top][All Lists]
Advanced
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[rdiff-backup-users] KeyError mtime followed by KeyError: 'uid'

From: Maik Weber
Subject: [rdiff-backup-users] KeyError mtime followed by KeyError: 'uid'
Date: Mon, 13 Dec 2010 09:08:38 +0100 
Dear all,

yesterday I migrated my system to a new larger hdd. All went well and
I tested that my usual system backup works, this is the command I run
as root:
rdiff-backup --exclude-globbing-filelist
~/scripts/system_backup/exclude.txt / /media/sdc1/newsys_backup
Yesterday evening at 7PM I ran it without errors.

I execute the same command nightly from cron. This night the command
failed with the error:
Warning, repeated index ('usr', 'share', 'foomatic', 'db', 'source',
'PPD', 'Sharp', 'sh555sj.ppd.gz'), bad filesystem?
That error was repeated 1997 times, followed by
Exception ''mtime'' raised of class '<type 'exceptions.KeyError'>':
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 304,
in error_check_Main
    try: Main(arglist)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 324, in Main
    take_action(rps)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 280,
in take_action
    elif action == "backup": Backup(rps[0], rps[1])
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 343, in Backup
    backup.Mirror_and_increment(rpin, rpout, incdir)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line 51,
in Mirror_and_increment
    DestS.patch_and_increment(dest_rpath, source_diffiter, inc_rpath)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
241, in patch_and_increment
    for diff in rorpiter.FillInIter(source_diffiter, dest_rpath):
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rorpiter.py", line
177, in FillInIter
    for rp in rpiter:
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
103, in get_diffs
    for dest_sig in dest_sigiter:
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
166, in get_sigs
    for src_rorp, dest_rorp in cls.CCPP:
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line 326, in next
    if len(self.cache_indicies) > self.cache_size: self.shorten_cache()
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
367, in shorten_cache
    changed_flag, success_flag, inc)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
417, in post_process
    self.metawriter.write_object(metadata_rorp)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/metadata.py", line
442, in write_object
    self.metawriter.write_object(rorp)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/metadata.py", line
401, in write_object
    self.write_record(self._object_to_record(object))
  File "/usr/lib/pymodules/python2.5/rdiff_backup/metadata.py", line
144, in RORP2Record
    str_list.append("  ModTime %s\n" % rorpath.getmtime())
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rpath.py", line 655,
in getmtime
    return self.data['mtime']

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/pymodules/python2.5/rdiff_backup/Main.py", line 304,
in error_check_Main
    try: Main(arglist)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 324, in Main
    take_action(rps)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 280,
in take_action
    elif action == "backup": Backup(rps[0], rps[1])
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 343, in Backup
    backup.Mirror_and_increment(rpin, rpout, incdir)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line 51,
in Mirror_and_increment
    DestS.patch_and_increment(dest_rpath, source_diffiter, inc_rpath)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
241, in patch_and_increment
    for diff in rorpiter.FillInIter(source_diffiter, dest_rpath):
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rorpiter.py", line
177, in FillInIter
    for rp in rpiter:
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
103, in get_diffs
    for dest_sig in dest_sigiter:
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
166, in get_sigs
    for src_rorp, dest_rorp in cls.CCPP:
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line 326, in next
    if len(self.cache_indicies) > self.cache_size: self.shorten_cache()
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
367, in shorten_cache
    changed_flag, success_flag, inc)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/backup.py", line
417, in post_process
    self.metawriter.write_object(metadata_rorp)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/metadata.py", line
442, in write_object
    self.metawriter.write_object(rorp)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/metadata.py", line
401, in write_object
    self.write_record(self._object_to_record(object))
  File "/usr/lib/pymodules/python2.5/rdiff_backup/metadata.py", line
144, in RORP2Record
    str_list.append("  ModTime %s\n" % rorpath.getmtime())
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rpath.py", line 655,
in getmtime
    return self.data['mtime']
KeyError: 'mtime'

When I saw this I ran fsck on the partition, but no errors were found.
I then executed the identical command once more (with -v9 included),
see output here:
n0x0n:~# clear;rdiff-backup -v9 --exclude-globbing-filelist
~/scripts/system_backup/exclude.txt / /media/sdc1/newsys_backup
Mon Dec 13 09:05:05 2010  Using rdiff-backup version 1.2.5
Mon Dec 13 09:05:05 2010  POSIX ACLs not supported by filesystem at /
Mon Dec 13 09:05:05 2010  Unable to import win32security module. Windows ACLs
not supported by filesystem at /
Mon Dec 13 09:05:05 2010  escape_dos_devices not required by filesystem at /
Mon Dec 13 09:05:05 2010
-----------------------------------------------------------------
Detected abilities for source (read only) file system:
  Access control lists                         Off
  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 Dec 13 09:05:05 2010  Making directory
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/5-_
a.snapshot.gz
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/5-_
a.snapshot.gz
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/uni?
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/uni?
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/:\"
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/:\"
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/A
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/A
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/foo
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/foo
Mon Dec 13 09:05:05 2010  Making directory
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/hl
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
Mon Dec 13 09:05:05 2010  Hard linking
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/hl/hardlinked_file2
to 
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/hardlinked_file1
Mon Dec 13 09:05:05 2010  Extended attributes not supported by
filesystem at /media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0
Mon Dec 13 09:05:05 2010  POSIX ACLs not supported by filesystem at
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0
Mon Dec 13 09:05:05 2010  Unable to import win32security module. Windows ACLs
not supported by filesystem at
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/dir_inc_check
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/regfile
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/regfile
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_file
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/high_perms_dir
Mon Dec 13 09:05:05 2010  Touching
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file2
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0/symlinked_file1
Mon Dec 13 09:05:05 2010  escape_dos_devices not required by
filesystem at /media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0
Mon Dec 13 09:05:05 2010  Deleting
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0
Mon Dec 13 09:05:05 2010  Removing directory
/media/sdc1/newsys_backup/rdiff-backup-data/rdiff-backup.tmp.0
Mon Dec 13 09:05:05 2010
-----------------------------------------------------------------
Detected abilities for destination (read/write) file system:
  Ownership changing                           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                         Off
  Extended attributes                          Off
  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 Dec 13 09:05:05 2010  Backup: must_escape_dos_devices = 0
Mon Dec 13 09:05:05 2010  Previous backup seems to have failed,
regressing destination now.
Mon Dec 13 09:05:05 2010  Regressing to Sun Dec 12 19:14:28 2010
Mon Dec 13 09:05:27 2010  Regressing file
usr/share/foomatic/db/source/PPD/Sharp/rdiff-backup.tmp.1
Mon Dec 13 09:05:27 2010  Deleting
/media/sdc1/newsys_backup/usr/share/foomatic/db/source/PPD/Sharp/rdiff-backup.tmp.1
Mon Dec 13 09:05:27 2010  Regular copying ('usr', 'share', 'foomatic',
'db', 'source', 'PPD', 'Sharp', 'rdiff-backup.tmp.1') to
/media/sdc1/newsys_backup/usr/share/foomatic/db/source/PPD/Sharp/rdiff-backup.tmp.1
Mon Dec 13 09:05:27 2010  Regressing file
usr/share/foomatic/db/source/PPD/Sharp/sh555sj.ppd.gz
Mon Dec 13 09:05:27 2010  Applying patch
usr/share/foomatic/db/source/PPD/Sharp/sh555sj.ppd.gz.2010-12-12T19:14:28+01:00.diff
Mon Dec 13 09:05:27 2010  Writing file object to
/media/sdc1/newsys_backup/usr/share/foomatic/db/source/PPD/Sharp/rdiff-backup.tmp.1
Mon Dec 13 09:05:28 2010  Copying attributes from ('usr', 'share',
'foomatic', 'db', 'source', 'PPD', 'Sharp', 'sh555sj.ppd.gz') to
/media/sdc1/newsys_backup/usr/share/foomatic/db/source/PPD/Sharp/rdiff-backup.tmp.1
Mon Dec 13 09:05:28 2010  Exception ''uid'' raised of class '<type
'exceptions.KeyError'>':
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 304,
in error_check_Main
    try: Main(arglist)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 324, in Main
    take_action(rps)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 280,
in take_action
    elif action == "backup": Backup(rps[0], rps[1])
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 337, in Backup
    backup_final_init(rpout)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 497,
in backup_final_init
    checkdest_if_necessary(rpout)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 905,
in checkdest_if_necessary
    dest_rp.conn.regress.Regress(dest_rp)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/regress.py", line
71, in Regress
    for rf in iterate_meta_rfs(mirror_rp, inc_rpath): ITR(rf.index, rf)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rorpiter.py", line
281, in __call__
    last_branch.fast_process(*args)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/regress.py", line
268, in fast_process
    if rf.metadata_rorp.isreg(): self.restore_orig_regfile(rf)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/regress.py", line
292, in restore_orig_regfile
    rpath.copy_attribs(rf.metadata_rorp, tf)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rpath.py", line 180,
in copy_attribs
    rpout.chown(*rpout.conn.user_group.map_rpath(rpin))
  File "/usr/lib/pymodules/python2.5/rdiff_backup/user_group.py", line
216, in map_rpath
    uid, gid = rp.getuidgid()
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rpath.py", line 647,
in getuidgid
    return self.data['uid'], self.data['gid']

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/pymodules/python2.5/rdiff_backup/Main.py", line 304,
in error_check_Main
    try: Main(arglist)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 324, in Main
    take_action(rps)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 280,
in take_action
    elif action == "backup": Backup(rps[0], rps[1])
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 337, in Backup
    backup_final_init(rpout)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 497,
in backup_final_init
    checkdest_if_necessary(rpout)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/Main.py", line 905,
in checkdest_if_necessary
    dest_rp.conn.regress.Regress(dest_rp)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/regress.py", line
71, in Regress
    for rf in iterate_meta_rfs(mirror_rp, inc_rpath): ITR(rf.index, rf)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rorpiter.py", line
281, in __call__
    last_branch.fast_process(*args)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/regress.py", line
268, in fast_process
    if rf.metadata_rorp.isreg(): self.restore_orig_regfile(rf)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/regress.py", line
292, in restore_orig_regfile
    rpath.copy_attribs(rf.metadata_rorp, tf)
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rpath.py", line 180,
in copy_attribs
    rpout.chown(*rpout.conn.user_group.map_rpath(rpin))
  File "/usr/lib/pymodules/python2.5/rdiff_backup/user_group.py", line
216, in map_rpath
    uid, gid = rp.getuidgid()
  File "/usr/lib/pymodules/python2.5/rdiff_backup/rpath.py", line 647,
in getuidgid
    return self.data['uid'], self.data['gid']
KeyError: 'uid'

Just to be sure I deleted the file and tried again, but the error
persists even after the file is removed.
Any ideas or thing I could try?

This might be interesting to debug, if not I'll just dump the
corrupted repository and create a new one...
Marty
reply via email to
[Prev in Thread] Current Thread [Next in Thread]