Bug fixes to resuming and error correction code

git-svn-id: http://svn.savannah.nongnu.org/svn/rdiff-backup@112 2b77aa54-bcbc-44c9-a7ec-4f6cf2b41109

trunk/rdiff-backup/rdiff_backup/destructive_stepping.py

@@ -189,7 +189,7 @@ class DSRPath(RPath):
 		return self.__class__(self.source, self.conn, self.base, index)
 
 
-class DestructiveSteppingFinalizer(IterTreeReducer):
+class DestructiveSteppingFinalizer(ErrorITR):
 		"""Finalizer that can work on an iterator of dsrpaths
 
 		The reason we have to use an IterTreeReducer is that some files
@@ -203,11 +203,6 @@ class DestructiveSteppingFinalizer(IterTreeReducer):
 			self.dsrpath = dsrpath
 
 		def end_process(self):
-			if self.dsrpath:
-				Robust.check_common_error(self.dsrpath.write_changes,
-					lambda exc: Log("Error %s finalizing file %s" %
-									(str(exc), dsrp.path)))
-
-
+			if self.dsrpath: self.dsrpath.write_changes()
 
 

trunk/rdiff-backup/rdiff_backup/header.py

 #!/usr/bin/env python
 #
 # rdiff-backup -- Mirror files while keeping incremental changes
-# Version 0.7.5.3 released May 25, 2002
+# Version 0.7.5.4 released May 29, 2002
 # Copyright (C) 2001, 2002 Ben Escoto <bescoto@stanford.edu>
 #
 # This program is licensed under the GNU General Public License (GPL).

trunk/rdiff-backup/rdiff_backup/highlevel.py

@@ -94,15 +94,18 @@ class HLSourceStruct:
 		"""
 		collated = RORPIter.CollateIterators(cls.initial_dsiter2, sigiter)
 		finalizer = DestructiveSteppingFinalizer()
+		def error_handler(exc, dest_sig, dsrp):
+			Log("Error %s producing a diff of %s" %
+				(exc, dsrp and dsrp.path), 2)
+			return None
+			
 		def diffs():
 			for dsrp, dest_sig in collated:
 				if dest_sig:
 					if dest_sig.isplaceholder(): yield dest_sig
 					else:
 						diff = Robust.check_common_error(
-							lambda: RORPIter.diffonce(dest_sig, dsrp),
-							lambda exc: Log("Error %s producing a diff of %s" %
-											(str(exc), dsrp and dsrp.path), 2))
+							error_handler, RORPIter.diffonce, dest_sig, dsrp)
 						if diff: yield diff
 				if dsrp: finalizer(dsrp.index, dsrp)
 			finalizer.Finish()
@@ -216,24 +219,24 @@ class HLDestinationStruct:
 		"""Apply diffs and finalize"""
 		collated = RORPIter.CollateIterators(diffs, cls.initial_dsiter2)
 		finalizer = cls.get_finalizer()
-		dsrp = None
-		
-		def error_checked():
-			"""Inner writing loop, check this for errors"""
-			indexed_tuple = collated.next()
-			Log("Processing %s" % str(indexed_tuple), 7)
-			diff_rorp, dsrp = indexed_tuple
+		diff_rorp, dsrp = None, None
+
+		def patch(diff_rorp, dsrp):
 			if not dsrp: dsrp = cls.get_dsrp(dest_rpath, diff_rorp.index)
 			if diff_rorp and not diff_rorp.isplaceholder():
 				RORPIter.patchonce_action(None, dsrp, diff_rorp).execute()
-			finalizer(dsrp.index, dsrp)
 			return dsrp
 
-		try:
-			while 1:
-				try: dsrp = cls.check_skip_error(error_checked, dsrp)
-				except StopIteration: break
-		except: Log.exception(1)
+		def error_handler(exc, diff_rorp, dsrp):
+			filename = dsrp and dsrp.path or os.path.join(*diff_rorp.index)
+			Log("Error: %s processing file %s" % (exc, filename), 2)
+		
+		for indexed_tuple in collated:
+			Log("Processing %s" % str(indexed_tuple), 7)
+			diff_rorp, dsrp = indexed_tuple
+			dsrp = Robust.check_common_error(error_handler, patch,
+											 diff_rorp, dsrp)
+			finalizer(dsrp.index, dsrp)
 		finalizer.Finish()
 
 	def patch_w_datadir_writes(cls, dest_rpath, diffs, inc_rpath):
@@ -243,25 +246,19 @@ class HLDestinationStruct:
 		Stats.open_dir_stats_file()
 		dsrp = None
 
-		def error_checked():
-			"""Inner writing loop, check this for errors"""
-			indexed_tuple = collated.next()
-			Log("Processing %s" % str(indexed_tuple), 7)
-			diff_rorp, dsrp = indexed_tuple
-			if not dsrp: dsrp = cls.get_dsrp(dest_rpath, diff_rorp.index)
-			if diff_rorp and diff_rorp.isplaceholder(): diff_rorp = None
-			ITR(dsrp.index, diff_rorp, dsrp)
-			finalizer(dsrp.index, dsrp)
-			return dsrp
-
 		try:
-			while 1:
-				try: dsrp = cls.check_skip_error(error_checked, dsrp)
-				except StopIteration: break
+			for indexed_tuple in collated:
+				Log("Processing %s" % str(indexed_tuple), 7)
+				diff_rorp, dsrp = indexed_tuple
+				if not dsrp: dsrp = cls.get_dsrp(dest_rpath, diff_rorp.index)
+				if diff_rorp and diff_rorp.isplaceholder(): diff_rorp = None
+				ITR(dsrp.index, diff_rorp, dsrp)
+				finalizer(dsrp.index, dsrp)
 				SaveState.checkpoint(ITR, finalizer, dsrp)
-			cls.check_skip_error(ITR.Finish, dsrp)
-			cls.check_skip_error(finalizer.Finish, dsrp)
+			ITR.Finish()
+			finalizer.Finish()
 		except: cls.handle_last_error(dsrp, finalizer, ITR)
+
 		if Globals.preserve_hardlinks: Hardlink.final_writedata()
 		Stats.close_dir_stats_file()
 		Stats.write_session_statistics(ITR)
@@ -274,54 +271,29 @@ class HLDestinationStruct:
 		Stats.open_dir_stats_file()
 		dsrp = None
 
-		def error_checked():
-			"""Inner writing loop, catch variety of errors from this"""
-			indexed_tuple = collated.next()
-			Log("Processing %s" % str(indexed_tuple), 7)
-			diff_rorp, dsrp = indexed_tuple
-			index = indexed_tuple.index
-			if not dsrp: dsrp = cls.get_dsrp(dest_rpath, index)
-			if diff_rorp and diff_rorp.isplaceholder(): diff_rorp = None
-			ITR(index, diff_rorp, dsrp)
-			finalizer(index, dsrp)
-			return dsrp
-
 		try:
-			while 1:
-				try: dsrp = cls.check_skip_error(error_checked, dsrp)
-				except StopIteration: break
+			for indexed_tuple in collated:
+				Log("Processing %s" % str(indexed_tuple), 7)
+				diff_rorp, dsrp = indexed_tuple
+				index = indexed_tuple.index
+				if not dsrp: dsrp = cls.get_dsrp(dest_rpath, index)
+				if diff_rorp and diff_rorp.isplaceholder(): diff_rorp = None
+				ITR(index, diff_rorp, dsrp)
+				finalizer(index, dsrp)
 				SaveState.checkpoint(ITR, finalizer, dsrp)
-			cls.check_skip_error(ITR.Finish, dsrp)
-			cls.check_skip_error(finalizer.Finish, dsrp)
+			ITR.Finish()
+			finalizer.Finish()
 		except: cls.handle_last_error(dsrp, finalizer, ITR)
+
 		if Globals.preserve_hardlinks: Hardlink.final_writedata()
 		Stats.close_dir_stats_file()
 		Stats.write_session_statistics(ITR)
 		SaveState.checkpoint_remove()
 
-	def check_skip_error(cls, thunk, dsrp):
-		"""Run thunk, catch certain errors skip files"""
-		try: return thunk()
-		except (EnvironmentError, SkipFileException, DSRPPermError,
-				RPathException), exc:
-			if (not isinstance(exc, EnvironmentError) or
-				(errno.errorcode[exc[0]] in
-				 ['EPERM', 'ENOENT', 'EACCES', 'EBUSY', 'EEXIST',
-				  'ENOTDIR', 'ENAMETOOLONG', 'EINTR', 'ENOTEMPTY',
-				  'EIO', # reported by docv
-				  'ETXTBSY' # reported by Campbell on some NT system
-				  ])):
-				Log.exception()
-				Log("Skipping file because of error after %s" %
-					(dsrp and dsrp.index,), 2)
-				return None
-			else:
-				Log.exception(1,2)
-				raise
-
 	def handle_last_error(cls, dsrp, finalizer, ITR):
 		"""If catch fatal error, try to checkpoint before exiting"""
-		Log.exception(1)
+		Log.exception(1, 2)
+		TracebackArchive.log()
 		SaveState.checkpoint(ITR, finalizer, dsrp, 1)
 		if Globals.preserve_hardlinks: Hardlink.final_checkpoint(Globals.rbdir)
 		SaveState.touch_last_file_definitive()

trunk/rdiff-backup/rdiff_backup/increment.py

+import traceback
 execfile("statistics.py")
 
 #######################################################################
@@ -121,7 +122,7 @@ class Inc:
 MakeStatic(Inc)
 
 
-class IncrementITR(StatsITR):
+class IncrementITR(ErrorITR, StatsITR):
 	"""Patch and increment mirror directory
 
 	This has to be an ITR because directories that have files in them
@@ -236,13 +237,8 @@ class IncrementITR(StatsITR):
 
 	def end_process(self):
 		"""Do final work when leaving a tree (directory)"""
-		try: diff_rorp, dsrp, incpref = self.diff_rorp, self.dsrp, self.incpref
-		except AttributeError: # This weren't set because of some error
-			return
-
-		if self.mirror_isdirectory:
-			if not diff_rorp and not self.changed: return
-
+		diff_rorp, dsrp, incpref = self.diff_rorp, self.dsrp, self.incpref
+		if self.mirror_isdirectory and (diff_rorp or self.changed):
 			if self.directory_replacement:
 				tf = self.directory_replacement
 				self.incrp = Robust.chain(
@@ -264,7 +260,7 @@ class IncrementITR(StatsITR):
 		self.add_file_stats(subinstance)
 
 
-class MirrorITR(StatsITR):
+class MirrorITR(ErrorITR, StatsITR):
 	"""Like IncrementITR, but only patch mirror directory, don't increment"""
 	# This is always None since no increments will be created
 	incrp = None
@@ -284,13 +280,9 @@ class MirrorITR(StatsITR):
 
 	def end_process(self):
 		"""Update statistics when leaving"""
-		try: diff_rorp, mirror_dsrp = self.diff_rorp, self.mirror_dsrp
-		except AttributeError: # Some error above prevented these being set
-			return
-		
-		self.end_stats(diff_rorp, mirror_dsrp)
-		if mirror_dsrp.isdir():
-			Stats.write_dir_stats_line(self, mirror_dsrp.index)
+		self.end_stats(self.diff_rorp, self.mirror_dsrp)
+		if self.mirror_dsrp.isdir():
+			Stats.write_dir_stats_line(self, self.mirror_dsrp.index)
 
 	def branch_process(self, subinstance):
 		"""Update statistics with subdirectory results"""

trunk/rdiff-backup/rdiff_backup/lazy.py

@@ -196,9 +196,9 @@ class IterTreeReducer:
 	iterator nature of the connection between hosts and the temporal
 	order in which the files are processed.
 
-	There are three stub functions below: start_process, end_process,
-	and branch_process.  A class that subclasses this one should fill
-	in these functions with real values.
+	There are four stub functions below: start_process, end_process,
+	branch_process, and check_for_errors.  A class that subclasses
+	this one will probably fill in these functions to do more.
 
 	It is important that this class be pickable, so keep that in mind
 	when subclassing (this is used to resume failed sessions).
@@ -210,6 +210,7 @@ class IterTreeReducer:
 		self.index = None
 		self.subinstance = None
 		self.finished = None
+		self.caught_exception, self.start_successful = None, None
 
 	def intree(self, index):
 		"""Return true if index is still in current tree"""
@@ -239,14 +240,33 @@ class IterTreeReducer:
 		"""Process a branch right after it is finished (stub)"""
 		pass
 
+	def check_for_errors(self, function, *args):
+		"""start/end_process is called by this function
+
+		Usually it will distinguish between two types of errors.  Some
+		are serious and will be reraised, others are caught and simply
+		invalidate the current instance by setting
+		self.caught_exception.
+
+		"""
+		try: return apply(function, args)
+		except: raise
+
 	def Finish(self):
 		"""Call at end of sequence to tie everything up"""
-		assert not self.finished, (self.base_index, self.index)
-		if self.subinstance:
-			self.subinstance.Finish()
-			self.branch_process(self.subinstance)
-		self.end_process()
-		self.finished = 1
+		if not self.start_successful or self.finished:
+			self.caught_exception = 1
+		if self.caught_exception: self.log_prev_error(self.index)
+		else:
+			if self.subinstance:
+				self.subinstance.Finish()
+				self.branch_process(self.subinstance)
+			self.check_for_errors(self.end_process)
+			self.finished = 1
+
+	def log_prev_error(self, index):
+		"""Call function if no pending exception"""
+		Log("Skipping %s because of previous error" % os.path.join(*index), 2)
 
 	def __call__(self, *args):
 		"""Process args, where args[0] is current position in iterator
@@ -263,18 +283,37 @@ class IterTreeReducer:
 		assert type(index) is types.TupleType, type(index)
 
 		if self.index is None:
-			self.start_process(*args)
+			self.check_for_errors(self.start_process, *args)
+			self.start_successful = 1
 			self.index = self.base_index = index
 			return 1
 
 		if index <= self.index:
 			Log("Warning: oldindex %s >= newindex %s" % (self.index, index), 2)
+			return 1
 
 		if not self.intree(index):
 			self.Finish()
 			return None
-		else:
-			self.process_w_subinstance(args)
-			self.index = index
-			return 1
+
+		if self.caught_exception: self.log_prev_error(index)
+		else: self.process_w_subinstance(args)
+		self.index = index
+		return 1
+
+
+class ErrorITR(IterTreeReducer):
+	"""Adds some error handling to above ITR, if ITR processes files"""
+	def on_error(self, exc, *args):
+		"""This is run on any exception in start/end-process"""
+		self.caught_exception = 1
+		if args and isinstance(args[0], tuple):
+			filename = os.path.join(*args[0])
+		elif self.index: filename = os.path.join(*self.index)
+		else: filename = "."
+		Log("Error '%s' processing %s" % (exc, filename), 2)
+
+	def check_for_errors(self, function, *args):
+		"""Catch some non-fatal errors"""
+		return Robust.check_common_error(self.on_error, function, *args)
 

trunk/rdiff-backup/rdiff_backup/log.py

-import time, sys
+import time, sys, traceback
 execfile("lazy.py")
 
 #######################################################################
@@ -121,7 +121,13 @@ class Logger:
 		Globals.Main.cleanup()
 		sys.exit(1)
 
-	def exception(self, only_terminal = 0, verbosity = 4):
+	def exception_to_string(self):
+		"""Return string version of current exception"""
+		type, value, tb = sys.exc_info()
+		return ("Exception '%s' raised of class '%s':\n%s" %
+				(value, type, "".join(traceback.format_tb(tb))))
+
+	def exception(self, only_terminal = 0, verbosity = 5):
 		"""Log an exception and traceback
 
 		If only_terminal is None, log normally.  If it is 1, then only
@@ -135,9 +141,6 @@ class Logger:
 			logging_func = self.__call__
 		else: logging_func = self.log_to_term
 
-		exc_info = sys.exc_info()
-		logging_func("Exception %s raised of class %s" %
-					 (exc_info[1], exc_info[0]), verbosity)
-		logging_func("".join(traceback.format_tb(exc_info[2])), verbosity+1)
+		logging_func(self.exception_to_string(), verbosity)
 
 Log = Logger()

trunk/rdiff-backup/rdiff_backup/robust.py

@@ -68,6 +68,7 @@ class RobustAction:
 			return self.final_func(init_val)
 		except Exception, exc: # Catch all errors
 			Log.exception()
+			TracebackArchive.add()
 			if ran_init_thunk: self.error_handler(exc, 1, init_val)
 			else: self.error_handler(exc, None, None)
 			raise exc
@@ -233,41 +234,59 @@ class Robust:
 			tf.setdata()
 		return Robust.make_tf_robustaction(init, tf, rp)
 
-	def check_common_error(init_thunk, error_thunk = lambda exc: None):
-		"""Execute init_thunk, if error, run error_thunk on exception
+	def check_common_error(error_handler, function, *args):
+		"""Apply function to args, if error, run error_handler on exception
 
 		This only catches certain exceptions which seems innocent
 		enough.
 
 		"""
-		try: return init_thunk()
+		try: return function(*args)
  		except (EnvironmentError, SkipFileException, DSRPPermError,
 				RPathException, RdiffException), exc:
+			TracebackArchive.add()
 			if (not isinstance(exc, EnvironmentError) or
 				(errno.errorcode[exc[0]] in
 				 ['EPERM', 'ENOENT', 'EACCES', 'EBUSY', 'EEXIST',
 				  'ENOTDIR', 'ENAMETOOLONG', 'EINTR', 'ENOTEMPTY',
-				  'EIO', # reported by docv
-				  'ETXTBSY' # reported by Campbell on some NT system
-				  ])):
+				  'EIO', 'ETXTBSY', 'ESRCH', 'EINVAL'])):
 				Log.exception()
-				return error_thunk(exc)
+				if error_handler: return error_handler(exc, *args)
 			else:
 				Log.exception(1, 2)
 				raise
 
 	def listrp(rp):
 		"""Like rp.listdir() but return [] if error, and sort results"""
-		def error_thunk(exc):
+		def error_handler(exc):
 			Log("Error listing directory %s" % rp.path, 2)
 			return []
-		dir_listing = Robust.check_common_error(rp.listdir, error_thunk)
+		dir_listing = Robust.check_common_error(error_handler, rp.listdir)
 		dir_listing.sort()
 		return dir_listing
 
 MakeStatic(Robust)
 
 
+class TracebackArchive:
+	"""Save last 10 caught exceptions, so they can be printed if fatal"""
+	_traceback_strings = []
+	def add(cls):
+		"""Add most recent exception to archived list"""
+		cls._traceback_strings.append(Log.exception_to_string())
+		if len(cls._traceback_strings) > 10:
+			cls._traceback_strings = cls._traceback_strings[:10]
+
+	def log(cls):
+		"""Print all exception information to log file"""
+		if cls._traceback_strings:
+			Log("------------ Old traceback info -----------\n%s"
+				"-------------------------------------------" %
+				("\n".join(cls._traceback_strings),), 3)
+
+MakeClass(TracebackArchive)
+
+
 class TempFileManager:
 	"""Manage temp files"""
 

trunk/rdiff-backup/rdiff_backup/rorpiter.py

@@ -57,6 +57,10 @@ class RORPIter:
 
 	def Signatures(rp_iter):
 		"""Yield signatures of rpaths in given rp_iter"""
+		def error_handler(exc, rp):
+			Log("Error generating signature for %s" % rp.path)
+			return None
+
 		for rp in rp_iter:
 			if rp.isplaceholder(): yield rp
 			else:
@@ -65,11 +69,9 @@ class RORPIter:
 					if rp.isflaglinked(): rorp.flaglinked()
 					else:
 						fp = Robust.check_common_error(
-							lambda: Rdiff.get_signature(rp))
+							error_handler, Rdiff.get_signature, rp)
 						if fp: rorp.setfile(fp)
-						else:
-							Log("Error generating signature for %s" % rp.path)
-							continue
+						else: continue
 				yield rorp
 
 	def GetSignatureIter(base_rp):

trunk/rdiff-backup/rdiff_backup/selection.py

@@ -91,10 +91,10 @@ class Select:
 			self.starting_index = starting_index
 			self.iter = self.iterate_starting_from(self.dsrpath,
 						            self.iterate_starting_from, sel_func)
-		else:
-			assert not iterate_parents
-			self.iter = self.Iterate(self.dsrpath, self.Iterate, sel_func)
-		self.iterate_parents = iterate_parents
+		else: self.iter = self.Iterate(self.dsrpath, self.Iterate, sel_func)
+
+		# only iterate parents if we are not starting from beginning
+		self.iterate_parents = starting_index is not None and iterate_parents
 		self.next = self.iter.next
 		self.__iter__ = lambda: self
 		return self
@@ -127,17 +127,18 @@ class Select:
 
 	def iterate_in_dir(self, dsrpath, rec_func, sel_func):
 		"""Iterate the dsrps in directory dsrpath."""
+		def error_handler(exc, filename):
+			Log("Error initializing file %s/%s" % (dsrpath.path, filename), 2)
+			return None
+
 		if self.quoting_on:
 			for subdir in FilenameMapping.get_quoted_dir_children(dsrpath):
 				for dsrp in rec_func(subdir, rec_func, sel_func): yield dsrp
 		else:
 			for filename in Robust.listrp(dsrpath):
 				new_dsrp = Robust.check_common_error(
-					lambda: dsrpath.append(filename))
-				if not new_dsrp:
-					Log("Error initializing file %s/%s" %
-						(dsrpath.path, filename), 2)
-				else:
+					error_handler, dsrpath.append, filename)
+				if new_dsrp:
 					for dsrp in rec_func(new_dsrp, rec_func, sel_func):
 						yield dsrp
 
@@ -208,7 +209,6 @@ class Select:
 
 		self.parse_last_excludes()
 		self.parse_rbdir_exclude()
-		self.parse_proc_exclude()
 
 	def parse_catch_error(self, exc):
 		"""Deal with selection error exc"""
@@ -231,11 +231,6 @@ pattern (such as '**') which matches the base directory.""" %
 		self.add_selection_func(
 			self.glob_get_tuple_sf(("rdiff-backup-data",), 0), 1)
 
-	def parse_proc_exclude(self):
-		"""Exclude the /proc directory if starting from /"""
-		if self.prefix == "/":
-			self.add_selection_func(self.glob_get_tuple_sf(("proc",), 0), 1)
-
 	def parse_last_excludes(self):
 		"""Exit with error if last selection function isn't an exclude"""
 		if (self.selection_functions and

trunk/rdiff-backup/rdiff_backup/statistics.py

@@ -286,7 +286,8 @@ class Stats:
 			"directory_statistics"), Time.curtime, suffix)
 
 		if cls._dir_stats_rp.lstat():
-			Log("Warning, statistics file %s already exists, appending", 2)
+			Log("Warning, statistics file %s already exists, appending" %
+				cls._dir_stats_rp.path, 2)
 			cls._dir_stats_fp = cls._dir_stats_rp.open("ab",
 													   Globals.compression)
 		else: cls._dir_stats_fp = \

trunk/rdiff-backup/src/destructive_stepping.py

@@ -189,7 +189,7 @@ class DSRPath(RPath):
 		return self.__class__(self.source, self.conn, self.base, index)
 
 
-class DestructiveSteppingFinalizer(IterTreeReducer):
+class DestructiveSteppingFinalizer(ErrorITR):
 		"""Finalizer that can work on an iterator of dsrpaths
 
 		The reason we have to use an IterTreeReducer is that some files
@@ -203,11 +203,6 @@ class DestructiveSteppingFinalizer(IterTreeReducer):
 			self.dsrpath = dsrpath
 
 		def end_process(self):
-			if self.dsrpath:
-				Robust.check_common_error(self.dsrpath.write_changes,
-					lambda exc: Log("Error %s finalizing file %s" %
-									(str(exc), dsrp.path)))
-
-
+			if self.dsrpath: self.dsrpath.write_changes()
 
 

trunk/rdiff-backup/src/globals.py

@@ -8,7 +8,7 @@ import re, os
 class Globals:
 
 	# The current version of rdiff-backup
-	version = "0.7.5.3"
+	version = "0.7.5.4"
 	
 	# If this is set, use this value in seconds as the current time
 	# instead of reading it from the clock.

trunk/rdiff-backup/src/header.py

 #!/usr/bin/env python
 #
 # rdiff-backup -- Mirror files while keeping incremental changes
-# Version 0.7.5.3 released May 25, 2002
+# Version 0.7.5.4 released May 29, 2002
 # Copyright (C) 2001, 2002 Ben Escoto <bescoto@stanford.edu>
 #
 # This program is licensed under the GNU General Public License (GPL).

trunk/rdiff-backup/src/highlevel.py

@@ -94,15 +94,18 @@ class HLSourceStruct:
 		"""
 		collated = RORPIter.CollateIterators(cls.initial_dsiter2, sigiter)
 		finalizer = DestructiveSteppingFinalizer()
+		def error_handler(exc, dest_sig, dsrp):
+			Log("Error %s producing a diff of %s" %
+				(exc, dsrp and dsrp.path), 2)
+			return None
+			
 		def diffs():
 			for dsrp, dest_sig in collated:
 				if dest_sig:
 					if dest_sig.isplaceholder(): yield dest_sig
 					else:
 						diff = Robust.check_common_error(
-							lambda: RORPIter.diffonce(dest_sig, dsrp),
-							lambda exc: Log("Error %s producing a diff of %s" %
-											(str(exc), dsrp and dsrp.path), 2))
+							error_handler, RORPIter.diffonce, dest_sig, dsrp)
 						if diff: yield diff
 				if dsrp: finalizer(dsrp.index, dsrp)
 			finalizer.Finish()
@@ -216,24 +219,24 @@ class HLDestinationStruct:
 		"""Apply diffs and finalize"""
 		collated = RORPIter.CollateIterators(diffs, cls.initial_dsiter2)
 		finalizer = cls.get_finalizer()
-		dsrp = None
-		
-		def error_checked():
-			"""Inner writing loop, check this for errors"""
-			indexed_tuple = collated.next()
-			Log("Processing %s" % str(indexed_tuple), 7)
-			diff_rorp, dsrp = indexed_tuple
+		diff_rorp, dsrp = None, None
+
+		def patch(diff_rorp, dsrp):
 			if not dsrp: dsrp = cls.get_dsrp(dest_rpath, diff_rorp.index)
 			if diff_rorp and not diff_rorp.isplaceholder():
 				RORPIter.patchonce_action(None, dsrp, diff_rorp).execute()
-			finalizer(dsrp.index, dsrp)
 			return dsrp
 
-		try:
-			while 1:
-				try: dsrp = cls.check_skip_error(error_checked, dsrp)
-				except StopIteration: break
-		except: Log.exception(1)
+		def error_handler(exc, diff_rorp, dsrp):
+			filename = dsrp and dsrp.path or os.path.join(*diff_rorp.index)
+			Log("Error: %s processing file %s" % (exc, filename), 2)
+		
+		for indexed_tuple in collated:
+			Log("Processing %s" % str(indexed_tuple), 7)
+			diff_rorp, dsrp = indexed_tuple
+			dsrp = Robust.check_common_error(error_handler, patch,
+											 diff_rorp, dsrp)
+			finalizer(dsrp.index, dsrp)
 		finalizer.Finish()
 
 	def patch_w_datadir_writes(cls, dest_rpath, diffs, inc_rpath):
@@ -243,25 +246,19 @@ class HLDestinationStruct:
 		Stats.open_dir_stats_file()
 		dsrp = None
 
-		def error_checked():
-			"""Inner writing loop, check this for errors"""
-			indexed_tuple = collated.next()
-			Log("Processing %s" % str(indexed_tuple), 7)
-			diff_rorp, dsrp = indexed_tuple
-			if not dsrp: dsrp = cls.get_dsrp(dest_rpath, diff_rorp.index)
-			if diff_rorp and diff_rorp.isplaceholder(): diff_rorp = None
-			ITR(dsrp.index, diff_rorp, dsrp)
-			finalizer(dsrp.index, dsrp)
-			return dsrp
-
 		try:
-			while 1:
-				try: dsrp = cls.check_skip_error(error_checked, dsrp)
-				except StopIteration: break
+			for indexed_tuple in collated:
+				Log("Processing %s" % str(indexed_tuple), 7)
+				diff_rorp, dsrp = indexed_tuple
+				if not dsrp: dsrp = cls.get_dsrp(dest_rpath, diff_rorp.index)
+				if diff_rorp and diff_rorp.isplaceholder(): diff_rorp = None
+				ITR(dsrp.index, diff_rorp, dsrp)
+				finalizer(dsrp.index, dsrp)
 				SaveState.checkpoint(ITR, finalizer, dsrp)
-			cls.check_skip_error(ITR.Finish, dsrp)
-			cls.check_skip_error(finalizer.Finish, dsrp)
+			ITR.Finish()
+			finalizer.Finish()
 		except: cls.handle_last_error(dsrp, finalizer, ITR)
+
 		if Globals.preserve_hardlinks: Hardlink.final_writedata()
 		Stats.close_dir_stats_file()
 		Stats.write_session_statistics(ITR)
@@ -274,54 +271,29 @@ class HLDestinationStruct:
 		Stats.open_dir_stats_file()
 		dsrp = None
 
-		def error_checked():
-			"""Inner writing loop, catch variety of errors from this"""
-			indexed_tuple = collated.next()
-			Log("Processing %s" % str(indexed_tuple), 7)
-			diff_rorp, dsrp = indexed_tuple
-			index = indexed_tuple.index
-			if not dsrp: dsrp = cls.get_dsrp(dest_rpath, index)
-			if diff_rorp and diff_rorp.isplaceholder(): diff_rorp = None
-			ITR(index, diff_rorp, dsrp)
-			finalizer(index, dsrp)
-			return dsrp
-
 		try:
-			while 1:
-				try: dsrp = cls.check_skip_error(error_checked, dsrp)
-				except StopIteration: break
+			for indexed_tuple in collated:
+				Log("Processing %s" % str(indexed_tuple), 7)
+				diff_rorp, dsrp = indexed_tuple
+				index = indexed_tuple.index
+				if not dsrp: dsrp = cls.get_dsrp(dest_rpath, index)
+				if diff_rorp and diff_rorp.isplaceholder(): diff_rorp = None
+				ITR(index, diff_rorp, dsrp)
+				finalizer(index, dsrp)
 				SaveState.checkpoint(ITR, finalizer, dsrp)
-			cls.check_skip_error(ITR.Finish, dsrp)
-			cls.check_skip_error(finalizer.Finish, dsrp)
+			ITR.Finish()
+			finalizer.Finish()
 		except: cls.handle_last_error(dsrp, finalizer, ITR)
+
 		if Globals.preserve_hardlinks: Hardlink.final_writedata()
 		Stats.close_dir_stats_file()
 		Stats.write_session_statistics(ITR)
 		SaveState.checkpoint_remove()
 
-	def check_skip_error(cls, thunk, dsrp):
-		"""Run thunk, catch certain errors skip files"""
-		try: return thunk()
-		except (EnvironmentError, SkipFileException, DSRPPermError,
-				RPathException), exc:
-			if (not isinstance(exc, EnvironmentError) or
-				(errno.errorcode[exc[0]] in
-				 ['EPERM', 'ENOENT', 'EACCES', 'EBUSY', 'EEXIST',
-				  'ENOTDIR', 'ENAMETOOLONG', 'EINTR', 'ENOTEMPTY',
-				  'EIO', # reported by docv
-				  'ETXTBSY' # reported by Campbell on some NT system
-				  ])):
-				Log.exception()
-				Log("Skipping file because of error after %s" %
-					(dsrp and dsrp.index,), 2)
-				return None
-			else:
-				Log.exception(1,2)
-				raise
-
 	def handle_last_error(cls, dsrp, finalizer, ITR):
 		"""If catch fatal error, try to checkpoint before exiting"""
-		Log.exception(1)
+		Log.exception(1, 2)
+		TracebackArchive.log()
 		SaveState.checkpoint(ITR, finalizer, dsrp, 1)
 		if Globals.preserve_hardlinks: Hardlink.final_checkpoint(Globals.rbdir)
 		SaveState.touch_last_file_definitive()

trunk/rdiff-backup/src/increment.py

+import traceback
 execfile("statistics.py")
 
 #######################################################################
@@ -121,7 +122,7 @@ class Inc:
 MakeStatic(Inc)
 
 
-class IncrementITR(StatsITR):
+class IncrementITR(ErrorITR, StatsITR):
 	"""Patch and increment mirror directory
 
 	This has to be an ITR because directories that have files in them
@@ -236,13 +237,8 @@ class IncrementITR(StatsITR):
 
 	def end_process(self):
 		"""Do final work when leaving a tree (directory)"""
-		try: diff_rorp, dsrp, incpref = self.diff_rorp, self.dsrp, self.incpref
-		except AttributeError: # This weren't set because of some error
-			return
-
-		if self.mirror_isdirectory:
-			if not diff_rorp and not self.changed: return
-
+		diff_rorp, dsrp, incpref = self.diff_rorp, self.dsrp, self.incpref
+		if self.mirror_isdirectory and (diff_rorp or self.changed):
 			if self.directory_replacement:
 				tf = self.directory_replacement
 				self.incrp = Robust.chain(
@@ -264,7 +260,7 @@ class IncrementITR(StatsITR):
 		self.add_file_stats(subinstance)
 
 
-class MirrorITR(StatsITR):
+class MirrorITR(ErrorITR, StatsITR):
 	"""Like IncrementITR, but only patch mirror directory, don't increment"""
 	# This is always None since no increments will be created
 	incrp = None
@@ -284,13 +280,9 @@ class MirrorITR(StatsITR):
 
 	def end_process(self):
 		"""Update statistics when leaving"""
-		try: diff_rorp, mirror_dsrp = self.diff_rorp, self.mirror_dsrp
-		except AttributeError: # Some error above prevented these being set
-			return
-		
-		self.end_stats(diff_rorp, mirror_dsrp)
-		if mirror_dsrp.isdir():
-			Stats.write_dir_stats_line(self, mirror_dsrp.index)
+		self.end_stats(self.diff_rorp, self.mirror_dsrp)
+		if self.mirror_dsrp.isdir():
+			Stats.write_dir_stats_line(self, self.mirror_dsrp.index)
 
 	def branch_process(self, subinstance):
 		"""Update statistics with subdirectory results"""

trunk/rdiff-backup/src/lazy.py

@@ -196,9 +196,9 @@ class IterTreeReducer:
 	iterator nature of the connection between hosts and the temporal
 	order in which the files are processed.
 
-	There are three stub functions below: start_process, end_process,
-	and branch_process.  A class that subclasses this one should fill
-	in these functions with real values.
+	There are four stub functions below: start_process, end_process,
+	branch_process, and check_for_errors.  A class that subclasses
+	this one will probably fill in these functions to do more.
 
 	It is important that this class be pickable, so keep that in mind
 	when subclassing (this is used to resume failed sessions).
@@ -210,6 +210,7 @@ class IterTreeReducer:
 		self.index = None
 		self.subinstance = None
 		self.finished = None
+		self.caught_exception, self.start_successful = None, None
 
 	def intree(self, index):
 		"""Return true if index is still in current tree"""
@@ -239,14 +240,33 @@ class IterTreeReducer:
 		"""Process a branch right after it is finished (stub)"""
 		pass
 
+	def check_for_errors(self, function, *args):
+		"""start/end_process is called by this function
+
+		Usually it will distinguish between two types of errors.  Some
+		are serious and will be reraised, others are caught and simply
+		invalidate the current instance by setting
+		self.caught_exception.
+
+		"""
+		try: return apply(function, args)
+		except: raise
+
 	def Finish(self):
 		"""Call at end of sequence to tie everything up"""
-		assert not self.finished, (self.base_index, self.index)
-		if self.subinstance:
-			self.subinstance.Finish()
-			self.branch_process(self.subinstance)
-		self.end_process()
-		self.finished = 1
+		if not self.start_successful or self.finished:
+			self.caught_exception = 1
+		if self.caught_exception: self.log_prev_error(self.index)
+		else:
+			if self.subinstance:
+				self.subinstance.Finish()
+				self.branch_process(self.subinstance)
+			self.check_for_errors(self.end_process)
+			self.finished = 1
+
+	def log_prev_error(self, index):
+		"""Call function if no pending exception"""
+		Log("Skipping %s because of previous error" % os.path.join(*index), 2)
 
 	def __call__(self, *args):
 		"""Process args, where args[0] is current position in iterator
@@ -263,18 +283,37 @@ class IterTreeReducer:
 		assert type(index) is types.TupleType, type(index)
 
 		if self.index is None:
-			self.start_process(*args)
+			self.check_for_errors(self.start_process, *args)
+			self.start_successful = 1
 			self.index = self.base_index = index
 			return 1
 
 		if index <= self.index:
 			Log("Warning: oldindex %s >= newindex %s" % (self.index, index), 2)
+			return 1
 
 		if not self.intree(index):
 			self.Finish()
 			return None
-		else:
-			self.process_w_subinstance(args)
-			self.index = index
-			return 1
+
+		if self.caught_exception: self.log_prev_error(index)
+		else: self.process_w_subinstance(args)
+		self.index = index
+		return 1
+
+
+class ErrorITR(IterTreeReducer):
+	"""Adds some error handling to above ITR, if ITR processes files"""
+	def on_error(self, exc, *args):
+		"""This is run on any exception in start/end-process"""
+		self.caught_exception = 1
+		if args and isinstance(args[0], tuple):
+			filename = os.path.join(*args[0])
+		elif self.index: filename = os.path.join(*self.index)
+		else: filename = "."
+		Log("Error '%s' processing %s" % (exc, filename), 2)
+
+	def check_for_errors(self, function, *args):
+		"""Catch some non-fatal errors"""
+		return Robust.check_common_error(self.on_error, function, *args)
 

trunk/rdiff-backup/src/log.py

-import time, sys
+import time, sys, traceback
 execfile("lazy.py")
 
 #######################################################################
@@ -121,7 +121,13 @@ class Logger:
 		Globals.Main.cleanup()
 		sys.exit(1)
 
-	def exception(self, only_terminal = 0, verbosity = 4):
+	def exception_to_string(self):
+		"""Return string version of current exception"""
+		type, value, tb = sys.exc_info()
+		return ("Exception '%s' raised of class '%s':\n%s" %
+				(value, type, "".join(traceback.format_tb(tb))))
+
+	def exception(self, only_terminal = 0, verbosity = 5):
 		"""Log an exception and traceback
 
 		If only_terminal is None, log normally.  If it is 1, then only
@@ -135,9 +141,6 @@ class Logger:
 			logging_func = self.__call__
 		else: logging_func = self.log_to_term
 
-		exc_info = sys.exc_info()
-		logging_func("Exception %s raised of class %s" %
-					 (exc_info[1], exc_info[0]), verbosity)
-		logging_func("".join(traceback.format_tb(exc_info[2])), verbosity+1)
+		logging_func(self.exception_to_string(), verbosity)
 
 Log = Logger()

trunk/rdiff-backup/src/robust.py

@@ -68,6 +68,7 @@ class RobustAction:
 			return self.final_func(init_val)
 		except Exception, exc: # Catch all errors
 			Log.exception()
+			TracebackArchive.add()
 			if ran_init_thunk: self.error_handler(exc, 1, init_val)
 			else: self.error_handler(exc, None, None)
 			raise exc
@@ -233,41 +234,59 @@ class Robust:
 			tf.setdata()
 		return Robust.make_tf_robustaction(init, tf, rp)
 
-	def check_common_error(init_thunk, error_thunk = lambda exc: None):
-		"""Execute init_thunk, if error, run error_thunk on exception
+	def check_common_error(error_handler, function, *args):
+		"""Apply function to args, if error, run error_handler on exception
 
 		This only catches certain exceptions which seems innocent
 		enough.
 
 		"""
-		try: return init_thunk()
+		try: return function(*args)
  		except (EnvironmentError, SkipFileException, DSRPPermError,
 				RPathException, RdiffException), exc:
+			TracebackArchive.add()
 			if (not isinstance(exc, EnvironmentError) or
 				(errno.errorcode[exc[0]] in
 				 ['EPERM', 'ENOENT', 'EACCES', 'EBUSY', 'EEXIST',
 				  'ENOTDIR', 'ENAMETOOLONG', 'EINTR', 'ENOTEMPTY',
-				  'EIO', # reported by docv
-				  'ETXTBSY' # reported by Campbell on some NT system
-				  ])):
+				  'EIO', 'ETXTBSY', 'ESRCH', 'EINVAL'])):
 				Log.exception()
-				return error_thunk(exc)
+				if error_handler: return error_handler(exc, *args)
 			else:
 				Log.exception(1, 2)
 				raise
 
 	def listrp(rp):
 		"""Like rp.listdir() but return [] if error, and sort results"""
-		def error_thunk(exc):
+		def error_handler(exc):
 			Log("Error listing directory %s" % rp.path, 2)
 			return []
-		dir_listing = Robust.check_common_error(rp.listdir, error_thunk)
+		dir_listing = Robust.check_common_error(error_handler, rp.listdir)
 		dir_listing.sort()
 		return dir_listing
 
 MakeStatic(Robust)
 
 
+class TracebackArchive:
+	"""Save last 10 caught exceptions, so they can be printed if fatal"""
+	_traceback_strings = []
+	def add(cls):
+		"""Add most recent exception to archived list"""
+		cls._traceback_strings.append(Log.exception_to_string())
+		if len(cls._traceback_strings) > 10:
+			cls._traceback_strings = cls._traceback_strings[:10]
+
+	def log(cls):
+		"""Print all exception information to log file"""
+		if cls._traceback_strings:
+			Log("------------ Old traceback info -----------\n%s"
+				"-------------------------------------------" %
+				("\n".join(cls._traceback_strings),), 3)
+
+MakeClass(TracebackArchive)
+
+
 class TempFileManager:
 	"""Manage temp files"""
 

trunk/rdiff-backup/src/rorpiter.py

@@ -57,6 +57,10 @@ class RORPIter:
 
 	def Signatures(rp_iter):
 		"""Yield signatures of rpaths in given rp_iter"""
+		def error_handler(exc, rp):
+			Log("Error generating signature for %s" % rp.path)
+			return None
+
 		for rp in rp_iter:
 			if rp.isplaceholder(): yield rp
 			else:
@@ -65,11 +69,9 @@ class RORPIter:
 					if rp.isflaglinked(): rorp.flaglinked()
 					else:
 						fp = Robust.check_common_error(
-							lambda: Rdiff.get_signature(rp))
+							error_handler, Rdiff.get_signature, rp)
 						if fp: rorp.setfile(fp)
-						else:
-							Log("Error generating signature for %s" % rp.path)
-							continue
+						else: continue
 				yield rorp
 
 	def GetSignatureIter(base_rp):

trunk/rdiff-backup/src/selection.py

@@ -91,10 +91,10 @@ class Select:
 			self.starting_index = starting_index
 			self.iter = self.iterate_starting_from(self.dsrpath,
 						            self.iterate_starting_from, sel_func)
-		else:
-			assert not iterate_parents
-			self.iter = self.Iterate(self.dsrpath, self.Iterate, sel_func)
-		self.iterate_parents = iterate_parents
+		else: self.iter = self.Iterate(self.dsrpath, self.Iterate, sel_func)
+
+		# only iterate parents if we are not starting from beginning
+		self.iterate_parents = starting_index is not None and iterate_parents
 		self.next = self.iter.next
 		self.__iter__ = lambda: self
 		return self
@@ -127,17 +127,18 @@ class Select:
 
 	def iterate_in_dir(self, dsrpath, rec_func, sel_func):
 		"""Iterate the dsrps in directory dsrpath."""
+		def error_handler(exc, filename):
+			Log("Error initializing file %s/%s" % (dsrpath.path, filename), 2)
+			return None
+
 		if self.quoting_on:
 			for subdir in FilenameMapping.get_quoted_dir_children(dsrpath):
 				for dsrp in rec_func(subdir, rec_func, sel_func): yield dsrp
 		else:
 			for filename in Robust.listrp(dsrpath):
 				new_dsrp = Robust.check_common_error(
-					lambda: dsrpath.append(filename))
-				if not new_dsrp:
-					Log("Error initializing file %s/%s" %
-						(dsrpath.path, filename), 2)
-				else:
+					error_handler, dsrpath.append, filename)
+				if new_dsrp:
 					for dsrp in rec_func(new_dsrp, rec_func, sel_func):
 						yield dsrp
 
@@ -208,7 +209,6 @@ class Select:
 
 		self.parse_last_excludes()
 		self.parse_rbdir_exclude()
-		self.parse_proc_exclude()
 
 	def parse_catch_error(self, exc):
 		"""Deal with selection error exc"""
@@ -231,11 +231,6 @@ pattern (such as '**') which matches the base directory.""" %
 		self.add_selection_func(
 			self.glob_get_tuple_sf(("rdiff-backup-data",), 0), 1)
 
-	def parse_proc_exclude(self):
-		"""Exclude the /proc directory if starting from /"""
-		if self.prefix == "/":
-			self.add_selection_func(self.glob_get_tuple_sf(("proc",), 0), 1)
-
 	def parse_last_excludes(self):
 		"""Exit with error if last selection function isn't an exclude"""
 		if (self.selection_functions and

trunk/rdiff-backup/src/statistics.py

@@ -286,7 +286,8 @@ class Stats:
 			"directory_statistics"), Time.curtime, suffix)
 
 		if cls._dir_stats_rp.lstat():
-			Log("Warning, statistics file %s already exists, appending", 2)
+			Log("Warning, statistics file %s already exists, appending" %
+				cls._dir_stats_rp.path, 2)
 			cls._dir_stats_fp = cls._dir_stats_rp.open("ab",
 													   Globals.compression)
 		else: cls._dir_stats_fp = \

trunk/rdiff-backup/testing/finaltest.py

@@ -43,7 +43,7 @@ class PathSetter(unittest.TestCase):
 
 	def reset_schema(self):
 		self.rb_schema = SourceDir + \
-			 "/rdiff-backup -v5 --remote-schema './chdir-wrapper %s' "
+			 "/rdiff-backup -v3 --remote-schema './chdir-wrapper %s' "
 
 	def refresh(self, *rp_list):
 		"""Reread data for the given rps"""

trunk/rdiff-backup/testing/incrementtest.py

@@ -6,7 +6,7 @@ rbexec("main.py")
 
 lc = Globals.local_connection
 Globals.change_source_perms = 1
-Log.setverbosity(5)
+Log.setverbosity(3)
 
 def getrp(ending):
 	return RPath(lc, "testfiles/various_file_types/" + ending)