Merge branch 'feature/logging' into develop

.coveragerc

@@ -6,6 +6,8 @@ omit =
     setup.py
     versioneer.py
     .tox/*
+    .eggs/*
+    *easy_install*
     */pypy/*
     */lib_pypy/*
     */distutils/*

COT/add_file.py

@@ -85,7 +85,7 @@ def run(self):
             self.UI.confirm_or_die("Replace existing file {0} with {1}?"
                                    .format(vm.get_path_from_file(file),
                                            FILE))
-            logger.warning("Overwriting existing File in VM")
+            logger.warning("Overwriting existing File in OVF")
 
         vm.add_file(FILE, file_id, file)
 

COT/cli.py

@@ -20,75 +20,6 @@
 import getpass
 import textwrap
 
-# Set logging defaults for all of COT
-from verboselogs import VerboseLogger
-logging.setLoggerClass(VerboseLogger)
-
-from coloredlogs import ColoredStreamHandler
-
-
-class COTStreamHandler(ColoredStreamHandler, object):
-
-    def __init__(self, level=logging.DEBUG, **kwargs):
-        super(COTStreamHandler, self).__init__(
-            level=level,
-            show_hostname=False,
-            show_name=False,
-            show_timestamps=False,
-            **kwargs)
-
-    def emit(self, record):
-        if record.levelno < self.level:
-            return
-        # Make sure the message is a string
-        message = record.msg
-        try:
-            if not isinstance(message, basestring):
-                message = unicode(message)
-        except NameError:
-            if not isinstance(message, str):
-                message = str(message)
-        # Colorize the log message text
-        severity = record.levelname
-        if severity in self.severity_to_style:
-            style = self.severity_to_style[severity]
-        else:
-            style = {}
-        message = self.wrap_style(text=message, **style)
-        # Compose the formatted log message
-        # We adjust the message verbosity based on the configured level
-        parts = []
-        if self.level <= logging.DEBUG:
-            parts.append(self.wrap_style(
-                text=self.render_timestamp(record.created, record.msecs),
-                **style))
-        parts.append(self.wrap_style(
-            text=("{0:9}".format(severity + ':')), **style))
-        if self.level <= logging.DEBUG:
-            parts.append(self.wrap_style(
-                text=self.render_name(record.name), faint=True, **style))
-        parts.append(message)
-        message = ' '.join(parts)
-        # Copy the original record so we don't break other handlers
-        import copy
-        record = copy.copy(record)
-        record.msg = message
-        logging.StreamHandler.emit(self, record)
-
-    def render_timestamp(self, created, msecs):
-        import time
-        return "%s.%03d" % (time.strftime('%H:%M:%S',
-                                          time.localtime(created)),
-                            msecs)
-
-    def render_name(self, name):
-        return "{0:22}".format(name + ':')
-
-COTHandler = COTStreamHandler()
-logging.getLogger('COT').addHandler(COTHandler)
-
-# Proceed with importing the rest of the needed modules now that logging is set
-
 from COT import __version_long__
 from COT.data_validation import InvalidInputError
 from COT.ui_shared import UI
@@ -110,10 +41,49 @@ def __init__(self):
         except NameError:
             self.input = input
         self.getpass = getpass.getpass
+        self.handler = None
+        self.master_logger = None
 
         self.create_parser()
         self.create_subparsers()
 
+    def formatter(self, verbosity=logging.INFO):
+        """Create formatter for log output.
+        We offer different (more verbose) formatting when debugging is enabled,
+        hence this need.
+        """
+        from colorlog import ColoredFormatter
+        log_colors = {
+            'DEBUG':    'blue',
+            'VERBOSE':  'cyan',
+            'INFO':     'green',
+            'WARNING':  'yellow',
+            'ERROR':    'red',
+            'CRITICAL': 'red',
+        }
+        format_string = "%(log_color)s"
+        datefmt = None
+        if verbosity <= logging.DEBUG:
+            format_string += "%(asctime)s.%(msecs)d "
+            datefmt = "%H:%M:%S"
+        format_string += "%(levelname)8s: "
+        if verbosity <= logging.VERBOSE:
+            format_string += "%(name)-22s "
+        format_string += "%(message)s"
+        return ColoredFormatter(format_string,
+                                datefmt=datefmt,
+                                log_colors=log_colors)
+
+    def set_verbosity(self, level):
+        if not self.handler:
+            self.handler = logging.StreamHandler()
+        self.handler.setLevel(level)
+        self.handler.setFormatter(self.formatter(level))
+        if not self.master_logger:
+            self.master_logger = logging.getLogger('COT')
+            self.master_logger.addHandler(self.handler)
+        self.master_logger.setLevel(level)
+
     def run(self, argv):
         args = self.parse_args(argv)
         return self.main(args)
@@ -253,13 +223,11 @@ def parse_args(self, argv):
         if not sys.stdin.isatty():
             args._force = True
 
-        self.force = args._force
-
         return args
 
     def main(self, args):
-        logging.getLogger('COT').setLevel(args._verbosity)
-        COTHandler.setLevel(args._verbosity)
+        self.force = args._force
+        self.set_verbosity(args._verbosity)
 
         if not args._subcommand:
             self.parser.error("too few arguments")
@@ -268,6 +236,9 @@ def main(self, args):
 
         # Call the appropriate submodule and handle any resulting errors
         arg_hash = vars(args)
+        del arg_hash["_verbosity"]
+        del arg_hash["_force"]
+        del arg_hash["_subcommand"]
         for (arg, value) in arg_hash.items():
             # When argparse is using both "nargs='+'" and "action=append",
             # this allows some flexibility in the user CLI, but the parsed
@@ -277,9 +248,6 @@ def main(self, args):
             if (isinstance(value, list) and
                     all(isinstance(v, list) for v in value)):
                 arg_hash[arg] = [v for l in value for v in l]
-        del arg_hash["_verbosity"]
-        del arg_hash["_force"]
-        del arg_hash["_subcommand"]
         try:
             # Set mandatory (CAPITALIZED) args first, then optional args
             for (arg, value) in arg_hash.items():
@@ -302,6 +270,11 @@ def main(self, args):
         except KeyboardInterrupt:
             sys.exit("\nAborted by user.")
         finally:
+            if self.master_logger:
+                self.master_logger.removeHandler(self.handler)
+                self.master_logger = None
+                self.handler.close()
+                self.handler = None
             args.instance.destroy()
         # All exceptions not handled explicitly above will result in a
         # stack trace and exit - this is ugly so the more specific handling we
@@ -311,7 +284,3 @@ def main(self, args):
 
 def main():
     CLI().run(sys.argv[1:])
-
-
-if __name__ == "__main__":
-    main()