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 _______________________________________________ rdiff-backup-users mailing list at rdiff-backup-users@nongnu.org http://lists.nongnu.org/mailman/listinfo/rdiff-backup-users Wiki URL: http://rdiff-backup.solutionsfirst.com.au/index.php/RdiffBackupWiki