? LOG-README ? build ? duplicity-foo ? testing/logtest.py Index: duplicity-bin =================================================================== RCS file: /sources/duplicity/duplicity/duplicity-bin,v retrieving revision 1.39 diff -u -p -r1.39 duplicity-bin --- duplicity-bin 21 Sep 2008 14:21:37 -0000 1.39 +++ duplicity-bin 10 Nov 2008 22:30:46 -0000 @@ -441,6 +441,7 @@ def check_last_manifest(col_stats): def main(): """Start/end here""" dup_time.setcurtime() + log.setup() action = commandline.ProcessCommandLine(sys.argv[1:]) col_stats = collections.CollectionsStatus(globals.backend, globals.archive_dir).set_values() @@ -508,6 +509,7 @@ def main(): else: incremental_backup(sig_chain) globals.backend.close() + log.shutdown() if exit_val is not None: sys.exit(exit_val) Index: duplicity/collections.py =================================================================== RCS file: /sources/duplicity/duplicity/duplicity/collections.py,v retrieving revision 1.27 diff -u -p -r1.27 collections.py --- duplicity/collections.py 9 Sep 2008 19:58:58 -0000 1.27 +++ duplicity/collections.py 10 Nov 2008 22:30:47 -0000 @@ -549,22 +549,25 @@ class CollectionsStatus: """Log various error messages if find incomplete/orphaned files""" assert self.values_set if self.orphaned_sig_names: - log.Log("Warning, found the following orphaned signature files:\n" - + "\n".join(self.orphaned_sig_names), 2) + log.Warn("Warning, found the following orphaned signature files:\n" + + "\n".join(self.orphaned_sig_names), + log.WarningCode.orphaned_sig) if self.other_sig_chains and sig_chain_warning: if self.matched_chain_pair: - log.Log("Warning, found unnecessary signature chain(s)", 2) + log.Warn("Warning, found unnecessary signature chain(s)", + log.WarningCode.unnecessary_sig) else: - log.Log("Warning, found signatures but no corresponding " - "backup files", 2) + log.Warn("Warning, found signatures but no corresponding " + "backup files", log.WarningCode.unmatched_sig) if self.incomplete_backup_sets: - log.Log("Warning, found incomplete backup sets, probably left " - "from aborted session", 2) + log.Warn("Warning, found incomplete backup sets, probably left " + "from aborted session", log.WarningCode.incomplete_backup) if self.orphaned_backup_sets: - log.Log("Warning, found the following orphaned backup files:\n" - + "\n".join(map(lambda x: str(x), - self.orphaned_backup_sets)), 2) + log.Warn("Warning, found the following orphaned backup files:\n" + + "\n".join(map(lambda x: str(x), + self.orphaned_backup_sets)), + log.WarningCode.orphaned_backup) def get_backup_chains(self, filename_list): """Split given filename_list into chains Index: duplicity/commandline.py =================================================================== RCS file: /sources/duplicity/duplicity/duplicity/commandline.py,v retrieving revision 1.49 diff -u -p -r1.49 commandline.py --- duplicity/commandline.py 16 Sep 2008 15:11:01 -0000 1.49 +++ duplicity/commandline.py 10 Nov 2008 22:30:47 -0000 @@ -80,6 +80,8 @@ options = ["allow-source-mismatch", "include-filelist-stdin", "include-globbing-filelist=", "include-regexp=", + "log-fd=", + "log-file=", "no-encryption", "no-print-statistics", "null-separator", @@ -217,7 +219,7 @@ def parse_cmdline_options(arglist): gpg.gpg_options = (gpg.gpg_options + ' ' + arg).strip() elif opt in ["-h", "--help"]: usage(); - sys.exit(1); + sys.exit(0); elif opt == "--include-filelist-stdin": select_opts.append(("--include-filelist", "standard input")) select_files.append(sys.stdin) @@ -229,6 +231,19 @@ def parse_cmdline_options(arglist): globals.null_separator = 1 elif opt == "--num-retries": globals.num_retries = int(arg) + elif opt == "--log-fd": + log_fd = int(arg) + if log_fd < 1: + command_line_error("log-fd must be greater than zero.") + try: + log.add_fd(log_fd) + except: + command_line_error("Cannot write to log-fd %s." % arg) + elif opt == "--log-file": + try: + log.add_file(arg) + except: + command_line_error("Cannot write to log-file %s." % arg) elif opt in ["-r", "--file-to-restore"]: globals.restore_dir = arg elif opt in ["-t", "--restore-time"]: @@ -262,7 +277,10 @@ def parse_cmdline_options(arglist): print "duplicity", str(globals.version) sys.exit(0) elif opt in ["-v", "--verbosity"]: - log.setverbosity(int(arg)) + verb = int(arg) + if verb < 0 or verb > 9: + command_line_error("verbosity must be between 0 and 9.") + log.setverbosity(verb) elif opt == "--volsize": globals.volsize = int(arg)*1024*1024 else: @@ -275,9 +293,9 @@ def parse_cmdline_options(arglist): def command_line_error(message): """Indicate a command line error and exit""" - sys.stderr.write("Command line error: %s\n" % (message,)) - sys.stderr.write("Enter 'duplicity --help' for help screen.\n") - sys.exit(1) + log.FatalError("Command line error: %s\n" + "Enter 'duplicity --help' for help screen.""" % (message,), + log.ErrorCode.command_line) def usage(): """Print terse usage info""" @@ -342,6 +360,8 @@ Options: --include-filelist-stdin --include-globbing-filelist --include-regexp + --log-fd + --log-file --no-encryption --no-print-statistics --null-separator Index: duplicity/gpg.py =================================================================== RCS file: /sources/duplicity/duplicity/duplicity/gpg.py,v retrieving revision 1.16 diff -u -p -r1.16 gpg.py --- duplicity/gpg.py 15 Sep 2008 22:42:06 -0000 1.16 +++ duplicity/gpg.py 10 Nov 2008 22:30:47 -0000 @@ -150,7 +150,7 @@ class GPGFile: if self.status_fp: self.set_signature() self.gpg_process.wait() - if log.verbosity >= 5: + if log.getverbosity() >= 5: self.print_log() self.logger_fp.close() self.closed = 1 Index: duplicity/log.py =================================================================== RCS file: /sources/duplicity/duplicity/duplicity/log.py,v retrieving revision 1.7 diff -u -p -r1.7 log.py --- duplicity/log.py 9 Sep 2008 19:58:58 -0000 1.7 +++ duplicity/log.py 10 Nov 2008 22:30:47 -0000 @@ -1,4 +1,5 @@ # Copyright 2002 Ben Escoto +# Copyright 2008 Michael Terry # # This file is part of duplicity. # @@ -18,46 +19,184 @@ """Log various messages depending on verbosity level""" +import os import sys +import logging -verbosity = 3 -termverbosity = 3 +MIN = 0 +ERROR = 0 +WARNING = 2 +NOTICE = 3 +INFO = 5 +DEBUG = 9 +MAX = 9 + +_logger = None + +def DupToLoggerLevel(verb): + """Convert duplicity level to the logging module's system, where higher is + more severe""" + return MAX - verb + 1 + +def LoggerToDupLevel(verb): + """Convert logging module level to duplicity's system, where lowere is + more severe""" + return DupToLoggerLevel(verb) -def Log(s, verb_level): +def Log(s, verb_level, code=1): """Write s to stderr if verbosity level low enough""" - if verb_level <= termverbosity: - if verb_level <= 2: - sys.stderr.write(s + "\n") - sys.stderr.flush() - else: - sys.stdout.write(s + "\n") - sys.stdout.flush() + global _logger + # currentCode is a terrible hack until duplicity depends on Python 2.5 + # and its logging 'extra' keyword that allows a custom record dictionary. + _logger.currentCode = code + _logger.log(DupToLoggerLevel(verb_level), s) + _logger.currentCode = 1 def Debug(s): """Shortcut used for debug message (verbosity 9).""" - Log(s, 9) + Log(s, DEBUG) def Info(s): """Shortcut used for info messages (verbosity 5).""" - Log(s, 5) + Log(s, INFO) def Notice(s): """Shortcut used for notice messages (verbosity 3, the default).""" - Log(s, 3) + Log(s, NOTICE) -def Warn(s): +class WarningCode: + """Enumeration class to hold warning code values. + These values should never change, as frontends rely upon them. + Don't use 0 or negative numbers.""" + generic = 1 + orphaned_sig = 2 + unnecessary_sig = 3 + unmatched_sig = 4 + incomplete_backup = 5 + orphaned_backup = 6 + +def Warn(s, code=WarningCode.generic): """Shortcut used for warning messages (verbosity 2)""" - Log(s, 2) + Log(s, WARNING, code) + +class ErrorCode: + """Enumeration class to hold error code values. + These values should never change, as frontends rely upon them. + Don't use 0 or negative numbers. This code is returned by duplicity + to indicate which error occurred via both exit code and log.""" + generic = 1 + command_line = 2 + source_mismatch = 3 -def FatalError(s): +def FatalError(s, code=ErrorCode.generic): """Write fatal error message and exit""" - sys.stderr.write(s + "\n") - sys.stderr.flush() - sys.exit(1) + Log(s, ERROR, code) + sys.exit(code) + +class DupLogRecord(logging.LogRecord): + """Custom log record that holds a message code""" + def __init__(self, code, *args, **kwargs): + global _logger + logging.LogRecord.__init__(self, *args, **kwargs) + self.code = code + +class DupLogger(logging.Logger): + """Custom logger that creates special code-bearing records""" + # currentCode is a terrible hack until duplicity depends on Python 2.5 + # and its logging 'extra' keyword that allows a custom record dictionary. + currentCode = 1 + def makeRecord(self, name, lvl, fn, lno, msg, args, exc_info, *argv, **kwargs): + return DupLogRecord(self.currentCode, name, lvl, fn, lno, msg, args, exc_info) + +class OutFilter(logging.Filter): + """Filter that only allows warning or less important messages""" + def filter(self, record): + return record.levelno <= DupToLoggerLevel(WARNING) + +class ErrFilter(logging.Filter): + """Filter that only allows messages more important than warnings""" + def filter(self, record): + return record.levelno > DupToLoggerLevel(WARNING) + +def setup(): + """Initialize logging""" + global _logger + if _logger: + return + + logging.setLoggerClass(DupLogger) + _logger = logging.getLogger("duplicity") + + # Set up our special level names + logging.addLevelName(DupToLoggerLevel(ERROR), "ERROR") + logging.addLevelName(DupToLoggerLevel(WARNING), "WARNING") + logging.addLevelName(DupToLoggerLevel(NOTICE), "NOTICE") + logging.addLevelName(DupToLoggerLevel(INFO), "INFO") + logging.addLevelName(DupToLoggerLevel(DEBUG), "DEBUG") + + # Default verbosity allows notices and above + setverbosity(NOTICE) + + # stdout and stderr are for different logging levels + outHandler = logging.StreamHandler(sys.stdout) + outHandler.addFilter(OutFilter()) + _logger.addHandler(outHandler) + + errHandler = logging.StreamHandler(sys.stderr) + errHandler.addFilter(ErrFilter()) + _logger.addHandler(errHandler) + +class MachineFormatter(logging.Formatter): + """Formatter that creates messages in a syntax easily consumable by other + processes.""" + def __init__(self): + logging.Formatter.__init__(self, "%(levelname)s %(code)s\n%(message)s") + + def format(self, record): + s = logging.Formatter.format(self, record) + # Indent each extra line with a dot and space so that the consumer + # knows it's a continuation, not a new message. Add a newline so + # consumers know the message is over. + return s.replace('\n', '\n. ') + '\n' + +class MachineFilter(logging.Filter): + """Filter that only allows levels that are consumable by other processes.""" + def filter(self, record): + # We only want to allow records that have level names. If the level + # does not have an associated name, there will be a space as the + # logging module expands levelname to "Level %d". This will confuse + # consumers. Even if we dropped the space, random levels may not + # mean anything to consumers. + s = logging.getLevelName(record.levelno) + return s.find(' ') == -1 + +def add_fd(fd): + """Add stream to which to write machine-readable logging""" + global _logger + handler = logging.StreamHandler(os.fdopen(fd, 'w')) + handler.setFormatter(MachineFormatter()) + handler.addFilter(MachineFilter()) + _logger.addHandler(handler) + +def add_file(filename): + """Add file to which to write machine-readable logging""" + global _logger + handler = logging.FileHandler(filename, 'w') + handler.setFormatter(MachineFormatter()) + handler.addFilter(MachineFilter()) + _logger.addHandler(handler) -def setverbosity(verb, termverb = None): +def setverbosity(verb): """Set the verbosity level""" - global verbosity, termverbosity - verbosity = verb - if termverb: termverbosity = termverb - else: termverbosity = verb + global _logger + _logger.setLevel(DupToLoggerLevel(verb)) + +def getverbosity(): + """Get the verbosity level""" + global _logger + return LoggerToDupLevel(_logger.getEffectiveLevel()) + +def shutdown(): + """Cleanup and flush loggers""" + logging.shutdown() + Index: duplicity/manifest.py =================================================================== RCS file: /sources/duplicity/duplicity/duplicity/manifest.py,v retrieving revision 1.4 diff -u -p -r1.4 manifest.py --- duplicity/manifest.py 9 Sep 2008 19:58:58 -0000 1.4 +++ duplicity/manifest.py 10 Nov 2008 22:30:48 -0000 @@ -62,7 +62,7 @@ Previous directory: %s""" % (self.local_ Aborting because you may have accidentally tried to backup two different data sets to the same remote location, or using the same archive directory. If this is not a mistake, use the ---allow-source-mismatch switch to avoid seeing this message""") +--allow-source-mismatch switch to avoid seeing this message""", log.ErrorCode.source_mismatch) def add_volume_info(self, vi): """Add volume info vi to manifest""" Index: testing/run-all-tests.sh =================================================================== RCS file: /sources/duplicity/duplicity/testing/run-all-tests.sh,v retrieving revision 1.7 diff -u -p -r1.7 run-all-tests.sh --- testing/run-all-tests.sh 4 Sep 2008 11:57:53 -0000 1.7 +++ testing/run-all-tests.sh 10 Nov 2008 22:30:48 -0000 @@ -11,6 +11,7 @@ alltests=" \ gpgtest2.py \ GnuPGInterfacetest.py \ lazytest.py \ + logtest.py \ manifesttest.py \ misctest.py \ patchdirtest.py \