still some problems witih 0.5.3
Alberto Accomazzi
Alberto Accomazzi <aaccomazzi@cfa.harvard.edu>
Wed, 06 Mar 2002 10:15:37 -0500
Hi Ben,
In message <200203060109.g2619ij09883@folly.Stanford.EDU>, Ben Escoto writes:
> >>>>> "AA" == Alberto Accomazzi <aaccomazzi@cfa.harvard.edu>
> >>>>> wrote the following on Tue, 05 Mar 2002 17:12:15 -0500
>
> AA> Ben,
>
> AA> unfortunately the patch seems to be a step backwards:
>
> AA> # rdiff-backup /proj/ads/soft
> AA> /proj/ads-md3/backups/proj.test/ads/soft Last backup dated Tue
> AA> Mar 5 10:32:56 2002 was aborted, but we aren't resuming it.
> AA> Waiting for process to close
> AA> Waiting for process to close
> AA> Waiting for process to close
> AA> Waiting for process to close
>
> This may be a stupid question, but how do you know the patch didn't
> fix things? I would have thought that the pre-patch rdiff-backup
> would have exited on the first "Waiting ..." message.
Hmm... after waiting a minute or so watching the message
"Waiting for process to close" I assumed the program was stuck somewhere
and would not come back to life. Now that you ask the question, I wonder
whether that was actually the case -- I should have run a strace on the
process.
> But I was under the impression that the error you were seeing was
> pretty rare, occurring in only some backup sets. I guess that it is
> actually quite common, occurring on most/all files?
Well, it did occur just on this particular set. The problem there was
that the backup set was originally created under a regular user id rather
than root, and it died because of a permission problem (this happened
running version 0.5.1). I then restarted the backup as root, and things
seemed to work ok until the problem described above. As I said, I am
happy to forget about this since I decided that from now on I will run
all my backups as root and hopefully will not find myself in this
predicament again, but wanted to report this as a problem if it helps
track down some unknown problems.
Speaking of problems, I have a new one today :-(
After running a full backup two days ago, I set up a cron job to do
incrementals on a daily basis, and I get the error below.
Funny thing is if I rerun the command right after a failure, it will
correctly update the file that it died on, but will then crash at the
next one. This is still using the stock 0.5.3 with python 2.2.
Thanks,
-- Alberto
# rdiff-backup -v 9 /proj/ads/soft /proj/ads-md3/backups/proj/ads/soft
Wed Mar 6 09:57:53 2002 Resuming aborted backup dated Wed Mar 6 09:52:50 2002
Wed Mar 6 09:57:53 2002 Getting signature of /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/MNRAS.refs
Wed Mar 6 09:57:53 2002 Writing file object to /tmp/@6487.0
Wed Mar 6 09:57:53 2002 Getting delta of /proj/ads/soft/abs/absload/test/MNRAS.refs with signature /tmp/@6487.0
Wed Mar 6 09:57:53 2002 Processing (None, Path: /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/!
Index: ('abs', 'absload', 'test', '!')
Data: {'gid': 102, 'uid': 102, 'mtime': 1014841974L, 'perms': 420, 'type': 'reg', 'size': 0L}).('abs', 'absload', 'test', '!')
Wed Mar 6 09:57:53 2002 Writing checkpoint time 1015426673.67
Wed Mar 6 09:57:53 2002 Renaming /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/rdiff-backup.tmp.0 to /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/checkpoint-data.2002-03-06T09:52:50-04:00.snapshot
Wed Mar 6 09:57:53 2002 Renaming /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/rdiff-backup.tmp.1 to /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/last-file-incremented.2002-03-06T09:52:50-04:00.snapshot
Wed Mar 6 09:57:54 2002 Processing (Index: ('abs', 'absload', 'test', 'MNRAS.refs')
Data: {'gid': 102, 'uid': 102, 'mtime': 1015352186L, 'perms': 420, 'filetype': 'diff', 'type': 'reg', 'size': 20800L}, Path: /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/MNRAS.refs
Index: ('abs', 'absload', 'test', 'MNRAS.refs')
Data: {'gid': 102, 'uid': 102, 'mtime': 1011792912L, 'perms': 420, 'type': 'reg', 'size': 989117L}).('abs', 'absload', 'test', 'MNRAS.refs')
Wed Mar 6 09:57:54 2002 Incrementing mirror file /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/MNRAS.refs
Wed Mar 6 09:57:54 2002 Writing file object to /tmp/@6487.1
Wed Mar 6 09:57:54 2002 Deleting /tmp/@6487.0
Wed Mar 6 09:57:54 2002 Patching /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/MNRAS.refs using /tmp/@6487.1 to /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/rdiff-backup.tmp.2 via /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/rdiff-backup.tmp.3
Wed Mar 6 09:57:54 2002 Writing file object to /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/increments/abs/absload/test/rdiff-backup.tmp.4
Wed Mar 6 09:57:54 2002 Copying attributes from ('abs', 'absload', 'test', 'MNRAS.refs') to /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/increments/abs/absload/test/rdiff-backup.tmp.4
Wed Mar 6 09:57:54 2002 Setting time of /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/increments/abs/absload/test/rdiff-backup.tmp.4 to 1011792912
Wed Mar 6 09:57:54 2002 Copying attributes from ('abs', 'absload', 'test', 'MNRAS.refs') to /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/rdiff-backup.tmp.3
Wed Mar 6 09:57:54 2002 Setting time of /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/rdiff-backup.tmp.3 to 1015352186
Wed Mar 6 09:57:54 2002 Renaming /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/rdiff-backup.tmp.3 to /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/rdiff-backup.tmp.2
Wed Mar 6 09:57:54 2002 Deleting /tmp/@6487.1
Wed Mar 6 09:57:54 2002 Renaming /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/increments/abs/absload/test/rdiff-backup.tmp.4 to /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/increments/abs/absload/test/MNRAS.refs.2002-03-04T10:44:34-04:00.snapshot
Wed Mar 6 09:57:55 2002 Renaming /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/rdiff-backup.tmp.2 to /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/MNRAS.refs
Wed Mar 6 09:57:55 2002 Getting signature of /proj/ads-md3/backups/proj/ads/soft/abs/absload/test/accno.config
Wed Mar 6 09:57:55 2002 Writing file object to /tmp/@6487.2
Wed Mar 6 09:57:55 2002 Exception ['rdiff', 'signature', '/proj/ads-md3/backups/proj/ads/soft/abs/absload/test/accno.config'] exited with value -1 raised of class __main__.RdiffException
Wed Mar 6 09:57:55 2002 File "/proj/ads/soft/utils/bin/rdiff-backup", line 4288, in diffs
else: yield RORPIter.diffonce(dest_sig, dsrp)
File "/proj/ads/soft/utils/bin/rdiff-backup", line 3319, in diffonce
new_rp))
File "/proj/ads/soft/utils/bin/rdiff-backup", line 1325, in get_delta_sigfileobj
sig_tf.write_from_fileobj(sig_fileobj)
File "/proj/ads/soft/utils/bin/rdiff-backup", line 2540, in write_from_fileobj
if fp.close() or outfp.close():
File "/proj/ads/soft/utils/bin/rdiff-backup", line 2601, in close
result = self.file.close()
File "/proj/ads/soft/utils/bin/rdiff-backup", line 1462, in close
raise RdiffException("%s exited with value %d" %
Wed Mar 6 09:57:55 2002 Exception not all arguments converted raised of class exceptions.TypeError
Wed Mar 6 09:57:55 2002 File "/proj/ads/soft/utils/bin/rdiff-backup", line 4435, in patch_increment_and_finalize
try: dsrp = cls.check_skip_error(error_checked)
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4447, in check_skip_error
try: return thunk()
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4418, in error_checked
indexed_tuple = collated.next()
File "/proj/ads/soft/utils/bin/rdiff-backup", line 3268, in Collate2Iters
try: relem1 = riter1.next()
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4292, in diffs
Log("Error processing %s, skipping" % dest_sig.index, 2)
Wed Mar 6 09:57:55 2002 Writing checkpoint time 1015426675.37
Wed Mar 6 09:57:55 2002 Renaming /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/rdiff-backup.tmp.5 to /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/checkpoint-data.2002-03-06T09:52:50-04:00.snapshot
Wed Mar 6 09:57:55 2002 Renaming /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/rdiff-backup.tmp.6 to /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/last-file-incremented.2002-03-06T09:52:50-04:00.snapshot
Wed Mar 6 09:57:55 2002 Touching /proj/ads-md3/backups/proj/ads/soft/rdiff-backup-data/last-file-definitive.2002-03-06T09:52:50-04:00.snapshot
Traceback (most recent call last):
File "/proj/ads/soft/utils/bin/rdiff-backup", line 5071, in ?
Globals.Main.Main()
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4817, in Main
self.take_action(rps)
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4793, in take_action
elif self.action == "backup": self.Backup(rps[0], rps[1])
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4847, in Backup
HighLevel.Mirror_and_increment(rpin, rpout, self.incdir, RSI)
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4238, in Mirror_and_increment
DestS.patch_increment_and_finalize(dest_rpath, diffiter, inc_rpath)
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4440, in patch_increment_and_finalize
except: cls.handle_last_error(last_dsrp, finalizer, ITR)
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4435, in patch_increment_and_finalize
try: dsrp = cls.check_skip_error(error_checked)
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4447, in check_skip_error
try: return thunk()
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4418, in error_checked
indexed_tuple = collated.next()
File "/proj/ads/soft/utils/bin/rdiff-backup", line 3268, in Collate2Iters
try: relem1 = riter1.next()
File "/proj/ads/soft/utils/bin/rdiff-backup", line 4292, in diffs
Log("Error processing %s, skipping" % dest_sig.index, 2)
TypeError: not all arguments converted