Added some error checking code, and a wrapper for easier profiling

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

16 files changed, 181 insertions, 50 deletions

diff --git a/rdiff-backup/rdiff_backup/destructive_stepping.py b/rdiff-backup/rdiff_backup/destructive_stepping.py
index ff3b42a..0d0d529 100644
--- a/rdiff-backup/rdiff_backup/destructive_stepping.py
+++ b/rdiff-backup/rdiff_backup/destructive_stepping.py
@@ -204,7 +204,11 @@ class DestructiveSteppingFinalizer(IterTreeReducer):
 			self.dsrpath = dsrpath
 
 		def end_process(self):
-			if self.dsrpath: self.dsrpath.write_changes()
+			if self.dsrpath:
+				Robust.check_common_error(self.dsrpath.write_changes,
+					lambda exc: Log("Error %s finalizing file %s" %
+									(str(exc), dsrp.path)))
+
 
 
 
diff --git a/rdiff-backup/rdiff_backup/highlevel.py b/rdiff-backup/rdiff_backup/highlevel.py
index 36ba55a..86738df 100644
--- a/rdiff-backup/rdiff_backup/highlevel.py
+++ b/rdiff-backup/rdiff_backup/highlevel.py
@@ -97,15 +97,15 @@ class HLSourceStruct:
 		finalizer = DestructiveSteppingFinalizer()
 		def diffs():
 			for dsrp, dest_sig in collated:
-				try:
-					if dest_sig:
-						if dest_sig.isplaceholder(): yield dest_sig
-						else: yield RORPIter.diffonce(dest_sig, dsrp)
-					if dsrp: finalizer(dsrp.index, dsrp)
-				except (IOError, OSError, RdiffException):
-					Log.exception()
-					Log("Error processing %s, skipping" %
-						str(dest_sig.index), 2)
+				if dest_sig:
+					if dest_sig.isplaceholder(): yield dest_sig
+					else:
+						try: yield RORPIter.diffonce(dest_sig, dsrp)
+						except (IOError, OSError, RdiffException):
+							Log.exception()
+							Log("Error producing a diff of %s" %
+								dsrp and dsrp.path)
+				if dsrp: finalizer(dsrp.index, dsrp)
 			finalizer.Finish()
 		return diffs()
 
diff --git a/rdiff-backup/rdiff_backup/log.py b/rdiff-backup/rdiff_backup/log.py
index facb729..60bf75b 100644
--- a/rdiff-backup/rdiff_backup/log.py
+++ b/rdiff-backup/rdiff_backup/log.py
@@ -121,8 +121,8 @@ class Logger:
 		Globals.Main.cleanup()
 		sys.exit(1)
 
-	def exception(self, only_terminal = 0):
-		"""Log an exception and traceback at verbosity 2
+	def exception(self, only_terminal = 0, verbosity = 4):
+		"""Log an exception and traceback
 
 		If only_terminal is None, log normally.  If it is 1, then only
 		log to disk if log file is local (self.log_file_open = 1).  If
@@ -137,8 +137,8 @@ class Logger:
 
 		exc_info = sys.exc_info()
 		logging_func("Exception %s raised of class %s" %
-					 (exc_info[1], exc_info[0]), 3)
-		logging_func("".join(traceback.format_tb(exc_info[2])), 3)
+					 (exc_info[1], exc_info[0]), verbosity)
+		logging_func("".join(traceback.format_tb(exc_info[2])), verbosity+1)
 		
 
 Log = Logger()
diff --git a/rdiff-backup/rdiff_backup/profiled_rdb.py b/rdiff-backup/rdiff_backup/profiled_rdb.py
new file mode 100755
index 0000000..91810c2
--- /dev/null
+++ b/rdiff-backup/rdiff_backup/profiled_rdb.py
@@ -0,0 +1,20 @@
+#!/usr/bin/env python
+
+"""Run rdiff-backup with profiling on
+
+Same as rdiff-backup but runs profiler, and prints profiling
+statistics afterwards.
+
+"""
+
+__no_execute__ = 1
+execfile("main.py")
+import profile, pstats
+profile.run("Globals.Main.Main(%s)" % repr(sys.argv[1:]), "profile-output")
+p = pstats.Stats("profile-output")
+p.sort_stats('time')
+p.print_stats(20)
+p.sort_stats('cumulative')
+p.print_stats(20)
+
+
diff --git a/rdiff-backup/rdiff_backup/robust.py b/rdiff-backup/rdiff_backup/robust.py
index cb09baa..da0acc4 100644
--- a/rdiff-backup/rdiff_backup/robust.py
+++ b/rdiff-backup/rdiff_backup/robust.py
@@ -191,6 +191,39 @@ 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
+
+		This only catches certain exceptions which seems innocent
+		enough.
+
+		"""
+		try: return init_thunk()
+ 		except (IOError, OSError, SkipFileException, DSRPPermError,
+				RPathException), exc:
+			Log.exception()
+			if (not isinstance(exc, IOError) or
+				(isinstance(exc, IOError) and
+				 (exp[0] in [2,  # Means that a file is missing
+							 5,  # Reported by docv (see list)
+							 13, # Permission denied IOError
+							 20, # Means a directory changed to non-dir
+							 26, # Requested by Campbell (see list) -
+                                 # happens on some NT systems
+							 36] # filename too long
+				 ))):
+				return error_thunk(exc)
+			else: raise
+
+	def listrp(rp):
+		"""Like rp.listdir() but return [] if error, and sort results"""
+		def error_thunk(exc):
+			Log("Error listing directory %s" % rp.path, 2)
+			return []
+		dir_listing = Robust.check_common_error(rp.listdir, error_thunk)
+		dir_listing.sort()
+		return dir_listing
+
 MakeStatic(Robust)
 
 
@@ -554,4 +587,4 @@ class ResumeSessionInfo:
 		self.mirror = mirror
 		self.last_index = last_index
 		self.last_definitive = last_definitive
-		self.ITR, self.finalizer, = ITR_state, finalizer_state
+		self.ITR, self.finalizer, = ITR, finalizer
diff --git a/rdiff-backup/rdiff_backup/rorpiter.py b/rdiff-backup/rdiff_backup/rorpiter.py
index bad02a4..fb30426 100644
--- a/rdiff-backup/rdiff_backup/rorpiter.py
+++ b/rdiff-backup/rdiff_backup/rorpiter.py
@@ -63,7 +63,13 @@ class RORPIter:
 				rorp = rp.getRORPath()
 				if rp.isreg():
 					if rp.isflaglinked(): rorp.flaglinked()
-					else: rorp.setfile(Rdiff.get_signature(rp))
+					else:
+						fp = Robust.check_common_error(
+							lambda: Rdiff.get_signature(rp))
+						if fp: rorp.setfile(fp)
+						else:
+							Log("Error generating signature for %s" % rp.path)
+							continue
 				yield rorp
 
 	def GetSignatureIter(base_rp):
diff --git a/rdiff-backup/rdiff_backup/selection.py b/rdiff-backup/rdiff_backup/selection.py
index bd679de..aa98a49 100644
--- a/rdiff-backup/rdiff_backup/selection.py
+++ b/rdiff-backup/rdiff_backup/selection.py
@@ -125,11 +125,14 @@ class Select:
 			for subdir in FilenameMapping.get_quoted_dir_children(dsrpath):
 				for dsrp in rec_func(subdir, rec_func, sel_func): yield dsrp
 		else:
-			dir_listing = dsrpath.listdir()
-			dir_listing.sort()
-			for filename in dir_listing:
-				for dsrp in rec_func(dsrpath.append(filename),
-									 rec_func, sel_func): yield dsrp
+			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" % dsrpath.path, 2)
+				else:
+					for dsrp in rec_func(new_dsrp, rec_func, sel_func):
+						yield dsrp
 
 	def iterate_starting_from(self, dsrpath, rec_func, sel_func):
 		"""Like Iterate, but only yield indicies > self.starting_index"""
diff --git a/rdiff-backup/src/destructive_stepping.py b/rdiff-backup/src/destructive_stepping.py
index ff3b42a..0d0d529 100644
--- a/rdiff-backup/src/destructive_stepping.py
+++ b/rdiff-backup/src/destructive_stepping.py
@@ -204,7 +204,11 @@ class DestructiveSteppingFinalizer(IterTreeReducer):
 			self.dsrpath = dsrpath
 
 		def end_process(self):
-			if self.dsrpath: self.dsrpath.write_changes()
+			if self.dsrpath:
+				Robust.check_common_error(self.dsrpath.write_changes,
+					lambda exc: Log("Error %s finalizing file %s" %
+									(str(exc), dsrp.path)))
+
 
 
 
diff --git a/rdiff-backup/src/filename_mapping.py b/rdiff-backup/src/filename_mapping.py
index 78c37d9..b8110be 100644
--- a/rdiff-backup/src/filename_mapping.py
+++ b/rdiff-backup/src/filename_mapping.py
@@ -80,7 +80,7 @@ class FilenameMapping:
 		"""For rpath directory, return list of quoted children in dir"""
 		if not rpath.isdir(): return []
 		dir_pairs = [(cls.unquote(filename), filename)
-					 for filename in rpath.listdir()]
+					 for filename in Robust.listrp(rpath)]
 		dir_pairs.sort() # sort by real index, not quoted part
 		child_list = []
 		for unquoted, filename in dir_pairs:
diff --git a/rdiff-backup/src/highlevel.py b/rdiff-backup/src/highlevel.py
index 36ba55a..86738df 100644
--- a/rdiff-backup/src/highlevel.py
+++ b/rdiff-backup/src/highlevel.py
@@ -97,15 +97,15 @@ class HLSourceStruct:
 		finalizer = DestructiveSteppingFinalizer()
 		def diffs():
 			for dsrp, dest_sig in collated:
-				try:
-					if dest_sig:
-						if dest_sig.isplaceholder(): yield dest_sig
-						else: yield RORPIter.diffonce(dest_sig, dsrp)
-					if dsrp: finalizer(dsrp.index, dsrp)
-				except (IOError, OSError, RdiffException):
-					Log.exception()
-					Log("Error processing %s, skipping" %
-						str(dest_sig.index), 2)
+				if dest_sig:
+					if dest_sig.isplaceholder(): yield dest_sig
+					else:
+						try: yield RORPIter.diffonce(dest_sig, dsrp)
+						except (IOError, OSError, RdiffException):
+							Log.exception()
+							Log("Error producing a diff of %s" %
+								dsrp and dsrp.path)
+				if dsrp: finalizer(dsrp.index, dsrp)
 			finalizer.Finish()
 		return diffs()
 
diff --git a/rdiff-backup/src/log.py b/rdiff-backup/src/log.py
index facb729..60bf75b 100644
--- a/rdiff-backup/src/log.py
+++ b/rdiff-backup/src/log.py
@@ -121,8 +121,8 @@ class Logger:
 		Globals.Main.cleanup()
 		sys.exit(1)
 
-	def exception(self, only_terminal = 0):
-		"""Log an exception and traceback at verbosity 2
+	def exception(self, only_terminal = 0, verbosity = 4):
+		"""Log an exception and traceback
 
 		If only_terminal is None, log normally.  If it is 1, then only
 		log to disk if log file is local (self.log_file_open = 1).  If
@@ -137,8 +137,8 @@ class Logger:
 
 		exc_info = sys.exc_info()
 		logging_func("Exception %s raised of class %s" %
-					 (exc_info[1], exc_info[0]), 3)
-		logging_func("".join(traceback.format_tb(exc_info[2])), 3)
+					 (exc_info[1], exc_info[0]), verbosity)
+		logging_func("".join(traceback.format_tb(exc_info[2])), verbosity+1)
 		
 
 Log = Logger()
diff --git a/rdiff-backup/src/main.py b/rdiff-backup/src/main.py
index a6c1ce0..b27dad7 100755
--- a/rdiff-backup/src/main.py
+++ b/rdiff-backup/src/main.py
@@ -16,14 +16,14 @@ class Main:
 		self.select_opts, self.select_mirror_opts = [], []
 		self.select_files = []
 
-	def parse_cmdlineoptions(self):
+	def parse_cmdlineoptions(self, arglist):
 		"""Parse argument list and set global preferences"""
 		def sel_fl(filename):
 			"""Helper function for including/excluding filelists below"""
 			try: return open(filename, "r")
 			except IOError: Log.FatalError("Error opening file %s" % filename)
 
-		try: optlist, self.args = getopt.getopt(sys.argv[1:], "blmr:sv:V",
+		try: optlist, self.args = getopt.getopt(arglist, "blmr:sv:V",
 			 ["backup-mode", "change-source-perms",
 			  "chars-to-quote=", "checkpoint-interval=",
 			  "current-time=", "exclude=", "exclude-device-files",
@@ -185,9 +185,9 @@ class Main:
 		Log.close_logfile()
 		if not Globals.server: SetConnections.CloseConnections()
 
-	def Main(self):
+	def Main(self, arglist):
 		"""Start everything up!"""
-		self.parse_cmdlineoptions()
+		self.parse_cmdlineoptions(arglist)
 		self.set_action()
 		rps = SetConnections.InitRPs(self.args,
 									 self.remote_schema, self.remote_cmd)
@@ -477,7 +477,6 @@ Try restoring from an increment file (the filenames look like
 		Manage.delete_earlier_than(datadir, time)
 		
 
-
+Globals.Main = Main()
 if __name__ == "__main__" and not globals().has_key('__no_execute__'):
-	Globals.Main = Main()
-	Globals.Main.Main()
+	Globals.Main.Main(sys.argv[1:])
diff --git a/rdiff-backup/src/profiled_rdb.py b/rdiff-backup/src/profiled_rdb.py
new file mode 100755
index 0000000..91810c2
--- /dev/null
+++ b/rdiff-backup/src/profiled_rdb.py
@@ -0,0 +1,20 @@
+#!/usr/bin/env python
+
+"""Run rdiff-backup with profiling on
+
+Same as rdiff-backup but runs profiler, and prints profiling
+statistics afterwards.
+
+"""
+
+__no_execute__ = 1
+execfile("main.py")
+import profile, pstats
+profile.run("Globals.Main.Main(%s)" % repr(sys.argv[1:]), "profile-output")
+p = pstats.Stats("profile-output")
+p.sort_stats('time')
+p.print_stats(20)
+p.sort_stats('cumulative')
+p.print_stats(20)
+
+
diff --git a/rdiff-backup/src/robust.py b/rdiff-backup/src/robust.py
index cb09baa..da0acc4 100644
--- a/rdiff-backup/src/robust.py
+++ b/rdiff-backup/src/robust.py
@@ -191,6 +191,39 @@ 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
+
+		This only catches certain exceptions which seems innocent
+		enough.
+
+		"""
+		try: return init_thunk()
+ 		except (IOError, OSError, SkipFileException, DSRPPermError,
+				RPathException), exc:
+			Log.exception()
+			if (not isinstance(exc, IOError) or
+				(isinstance(exc, IOError) and
+				 (exp[0] in [2,  # Means that a file is missing
+							 5,  # Reported by docv (see list)
+							 13, # Permission denied IOError
+							 20, # Means a directory changed to non-dir
+							 26, # Requested by Campbell (see list) -
+                                 # happens on some NT systems
+							 36] # filename too long
+				 ))):
+				return error_thunk(exc)
+			else: raise
+
+	def listrp(rp):
+		"""Like rp.listdir() but return [] if error, and sort results"""
+		def error_thunk(exc):
+			Log("Error listing directory %s" % rp.path, 2)
+			return []
+		dir_listing = Robust.check_common_error(rp.listdir, error_thunk)
+		dir_listing.sort()
+		return dir_listing
+
 MakeStatic(Robust)
 
 
@@ -554,4 +587,4 @@ class ResumeSessionInfo:
 		self.mirror = mirror
 		self.last_index = last_index
 		self.last_definitive = last_definitive
-		self.ITR, self.finalizer, = ITR_state, finalizer_state
+		self.ITR, self.finalizer, = ITR, finalizer
diff --git a/rdiff-backup/src/rorpiter.py b/rdiff-backup/src/rorpiter.py
index bad02a4..fb30426 100644
--- a/rdiff-backup/src/rorpiter.py
+++ b/rdiff-backup/src/rorpiter.py
@@ -63,7 +63,13 @@ class RORPIter:
 				rorp = rp.getRORPath()
 				if rp.isreg():
 					if rp.isflaglinked(): rorp.flaglinked()
-					else: rorp.setfile(Rdiff.get_signature(rp))
+					else:
+						fp = Robust.check_common_error(
+							lambda: Rdiff.get_signature(rp))
+						if fp: rorp.setfile(fp)
+						else:
+							Log("Error generating signature for %s" % rp.path)
+							continue
 				yield rorp
 
 	def GetSignatureIter(base_rp):
diff --git a/rdiff-backup/src/selection.py b/rdiff-backup/src/selection.py
index bd679de..aa98a49 100644
--- a/rdiff-backup/src/selection.py
+++ b/rdiff-backup/src/selection.py
@@ -125,11 +125,14 @@ class Select:
 			for subdir in FilenameMapping.get_quoted_dir_children(dsrpath):
 				for dsrp in rec_func(subdir, rec_func, sel_func): yield dsrp
 		else:
-			dir_listing = dsrpath.listdir()
-			dir_listing.sort()
-			for filename in dir_listing:
-				for dsrp in rec_func(dsrpath.append(filename),
-									 rec_func, sel_func): yield dsrp
+			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" % dsrpath.path, 2)
+				else:
+					for dsrp in rec_func(new_dsrp, rec_func, sel_func):
+						yield dsrp
 
 	def iterate_starting_from(self, dsrpath, rec_func, sel_func):
 		"""Like Iterate, but only yield indicies > self.starting_index"""