Merge pull request #654 from vkarak/refactor/colorize-logger

[refactor] Refactor `PrettyPrinter` and enable colors in the general logger

Author: vkarak

reframe/core/logging.py

@@ -11,6 +11,7 @@
 from datetime import datetime
 
 import reframe
+import reframe.utility.color as color
 import reframe.core.debug as debug
 import reframe.utility.os_ext as os_ext
 from reframe.core.exceptions import ConfigError, LoggingError
@@ -352,6 +353,7 @@ def __init__(self, logger=None, check=None):
             }
         )
         self.check = check
+        self.colorize = False
 
     def __repr__(self):
         return debug.repr(self)
@@ -415,6 +417,21 @@ def log(self, level, msg, *args, **kwargs):
     def verbose(self, message, *args, **kwargs):
         self.log(VERBOSE, message, *args, **kwargs)
 
+    def warning(self, message, *args, **kwargs):
+        message = '%s: %s' % (sys.argv[0], message)
+        if self.colorize:
+            message = color.colorize(message, color.YELLOW)
+
+        super().warning(message, *args, **kwargs)
+
+    def error(self, message, *args, **kwargs):
+        message = '%s: %s' % (sys.argv[0], message)
+        if self.colorize:
+            message = color.colorize(message, color.RED)
+
+        super().error(message, *args, **kwargs)
+
+
 
 # A logger that doesn't log anything
 null_logger = LoggerAdapter()

reframe/frontend/argparse.py

@@ -138,3 +138,11 @@ def parse_args(self, args=None, namespace=None):
                 )
 
         return options
+
+
+def format_options(namespace):
+    """Format parsed arguments in ``namespace``."""
+    ret = 'Command-line configuration:\n'
+    ret += '\n'.join(['    %s=%s' % (attr, val)
+                      for attr, val in sorted(namespace.__dict__.items())])
+    return ret

reframe/frontend/cli.py

@@ -8,19 +8,20 @@
 import reframe.core.config as config
 import reframe.core.logging as logging
 import reframe.core.runtime as runtime
+import reframe.frontend.argparse as argparse
 import reframe.frontend.check_filters as filters
 import reframe.utility as util
 import reframe.utility.os_ext as os_ext
 from reframe.core.exceptions import (EnvironError, ConfigError, ReframeError,
                                      ReframeFatalError, format_exception,
                                      SystemAutodetectionError)
-from reframe.frontend.argparse import ArgumentParser
 from reframe.frontend.executors import Runner
 from reframe.frontend.executors.policies import (SerialExecutionPolicy,
                                                  AsynchronousExecutionPolicy)
 from reframe.frontend.loader import RegressionCheckLoader
 from reframe.frontend.printer import PrettyPrinter
 
+
 def format_check(check, detailed):
     lines = ['  * %s (found in %s)' % (check.name,
                                        inspect.getfile(type(check)))]
@@ -48,7 +49,7 @@ def list_checks(checks, printer, detailed=False):
 
 def main():
     # Setup command line options
-    argparser = ArgumentParser()
+    argparser = argparse.ArgumentParser()
     output_options = argparser.add_argument_group(
         'Options controlling regression directories')
     locate_options = argparser.add_argument_group(
@@ -255,6 +256,9 @@ def main():
         sys.stderr.write('could not configure logging: %s\n' % e)
         sys.exit(1)
 
+    # Set colors in logger
+    logging.getlogger().colorize = options.colorize
+
     # Setup printer
     printer = PrettyPrinter()
     printer.colorize = options.colorize
@@ -377,7 +381,7 @@ def main():
             prefix=reframe.INSTALL_PREFIX,
             recurse=settings.checks_path_recurse)
 
-    printer.log_config(options)
+    printer.debug(argparse.format_options(options))
 
     # Print command line
     printer.info('Command line: %s' % ' '.join(sys.argv))
@@ -452,7 +456,7 @@ def main():
                 rt.modules_system.load_module(m, force=True)
                 raise EnvironError("test")
             except EnvironError as e:
-                printer.warning("could not load module '%s' correctly: " 
+                printer.warning("could not load module '%s' correctly: "
                                 "Skipping..." % m)
                 printer.debug(str(e))
 

reframe/frontend/executors/__init__.py

@@ -172,7 +172,7 @@ def runall(self, checks):
             self._printer.separator('short double line',
                                     'Running %d check(s)' % len(checks))
             self._printer.timestamp('Started on', 'short double line')
-            self._printer.info()
+            self._printer.info('')
             self._runall(checks)
             if self._max_retries:
                 self._retry_failed(checks)

reframe/frontend/printer.py

@@ -1,65 +1,24 @@
-import abc
 import datetime
 import sys
 
-import reframe.core.debug as debug
 import reframe.core.logging as logging
-
-
-class Colorizer(abc.ABC):
-    def __repr__(self):
-        return debug.repr(self)
-
-    @abc.abstractmethod
-    def colorize(string, foreground, background):
-        """Colorize a string.
-
-        Keyword arguments:
-        string -- the string to be colorized
-        foreground -- the foreground color
-        background -- the background color
-        """
-
-
-class AnsiColorizer(Colorizer):
-    escape_seq = '\033'
-    reset_term = '[0m'
-
-    # Escape sequences for fore/background colors
-    fgcolor = '[3'
-    bgcolor = '[4'
-
-    # color values
-    black   = '0m'
-    red     = '1m'
-    green   = '2m'
-    yellow  = '3m'
-    blue    = '4m'
-    magenta = '5m'
-    cyan    = '6m'
-    white   = '7m'
-    default = '9m'
-
-    def colorize(string, foreground, background=None):
-        return (AnsiColorizer.escape_seq +
-                AnsiColorizer.fgcolor + foreground + string +
-                AnsiColorizer.escape_seq + AnsiColorizer.reset_term)
+import reframe.utility.color as color
 
 
 class PrettyPrinter:
     """Pretty printing facility for the framework.
 
-    Final printing is delegated to an internal logger, which is responsible for
-    printing both to standard output and in a special output file."""
+    It takes care of formatting the progress output and adds some more
+    cosmetics to specific levels of messages, such as warnings and errors.
+
+    The actual printing is delegated to an internal logger, which is
+    responsible for printing.
+    """
 
     def __init__(self):
         self.colorize = True
         self.line_width = 78
         self.status_width = 10
-        self._logger = logging.getlogger()
-
-    def __repr__(self):
-        return debug.repr(self)
 
     def separator(self, linestyle, msg=''):
         if linestyle == 'short double line':
@@ -82,13 +41,13 @@ def status(self, status, message='', just=None, level=logging.INFO):
         if self.colorize:
             status_stripped = status.strip().lower()
             if status_stripped == 'skip':
-                status = AnsiColorizer.colorize(status, AnsiColorizer.yellow)
+                status = color.colorize(status, color.YELLOW)
             elif status_stripped in ['fail', 'failed']:
-                status = AnsiColorizer.colorize(status, AnsiColorizer.red)
+                status = color.colorize(status, color.RED)
             else:
-                status = AnsiColorizer.colorize(status, AnsiColorizer.green)
+                status = color.colorize(status, color.GREEN)
 
-        self._logger.log(level, '[ %s ] %s' % (status, message))
+        logging.getlogger().log(level, '[ %s ] %s' % (status, message))
 
     def result(self, check, partition, environ, success):
         if success:
@@ -107,24 +66,6 @@ def timestamp(self, msg='', separator=None):
         else:
             self.info(msg)
 
-    def info(self, msg=''):
-        self._logger.info(msg)
-
-    def debug(self, msg=''):
-        self._logger.debug(msg)
-
-    def warning(self, msg):
-        msg = AnsiColorizer.colorize('%s: %s' % (sys.argv[0], msg),
-                                     AnsiColorizer.yellow)
-        self._logger.warning(msg)
-
-    def error(self, msg):
-        msg = AnsiColorizer.colorize('%s: %s' % (sys.argv[0], msg),
-                                     AnsiColorizer.red)
-        self._logger.error(msg)
-
-    def log_config(self, options):
-        opt_list = ['    %s=%s' % (attr, val)
-                    for attr, val in sorted(options.__dict__.items())]
-
-        self._logger.debug('configuration\n%s' % '\n'.join(opt_list))
+    def __getattr__(self, attr):
+        # delegate all other attribute lookup to the underlying logger
+        return getattr(logging.getlogger(), attr)

reframe/utility/__init__.py

@@ -1,3 +1,4 @@
+import abc
 import collections
 import importlib
 import importlib.util

reframe/utility/color.py

@@ -0,0 +1,85 @@
+class ColorRGB:
+    def __init__(self, r, g, b):
+        self.__check_rgb(r)
+        self.__check_rgb(g)
+        self.__check_rgb(b)
+        self.__r = r
+        self.__g = g
+        self.__b = b
+
+    def __check_rgb(self, x):
+        if (x < 0) or x > 255:
+            raise ValueError('RGB color code must be in [0,255]')
+
+    @property
+    def r(self):
+        return self.__r
+
+    @property
+    def g(self):
+        return self.__g
+
+    @property
+    def b(self):
+        return self.__b
+
+    def __repr__(self):
+        return 'ColorRGB(%s, %s, %s)' % (self.__r, self.__g, self.__b)
+
+
+# Predefined colors
+BLACK   = ColorRGB(0, 0, 0)
+RED     = ColorRGB(255, 0, 0)
+GREEN   = ColorRGB(0, 255, 0)
+YELLOW  = ColorRGB(255, 255, 0)
+BLUE    = ColorRGB(0, 0, 255)
+MAGENTA = ColorRGB(255, 0, 255)
+CYAN    = ColorRGB(0, 255, 255)
+WHITE   = ColorRGB(255, 255, 255)
+
+
+class _AnsiPalette:
+    """Class for colorizing strings using ANSI meta-characters."""
+
+    escape_seq = '\033'
+    reset_term = '[0m'
+
+    # Escape sequences for fore/background colors
+    fgcolor = '[3'
+    bgcolor = '[4'
+
+    # color values
+    colors = {
+        BLACK:   '0m',
+        RED:     '1m',
+        GREEN:   '2m',
+        YELLOW:  '3m',
+        BLUE:    '4m',
+        MAGENTA: '5m',
+        CYAN:    '6m',
+        WHITE:   '7m'
+    }
+
+    def colorize(string, foreground):
+        try:
+            foreground = _AnsiPalette.colors[foreground]
+        except KeyError:
+            raise ValueError('could not find an ANSI representation '
+                             'for color: %s' % foreground) from None
+
+        return (_AnsiPalette.escape_seq +
+                _AnsiPalette.fgcolor + foreground + string +
+                _AnsiPalette.escape_seq + _AnsiPalette.reset_term)
+
+
+def colorize(string, foreground, *, palette='ANSI'):
+    """Colorize a string.
+
+    :arg string: The string to be colorized.
+    :arg foreground: The foreground color.
+    :arg palette: The palette to get colors from.
+    """
+    if palette != 'ANSI':
+        raise ValueError('unknown color palette: %s' % palette)
+
+    return _AnsiPalette.colorize(string, foreground)

unittests/test_color.py

@@ -0,0 +1,27 @@
+import unittest
+
+import reframe.utility.color as color
+
+
+class TestColors(unittest.TestCase):
+    def test_color_rgb(self):
+        c = color.ColorRGB(128, 0, 34)
+        self.assertEqual(128, c.r)
+        self.assertEqual(0, c.g)
+        self.assertEqual(34, c.b)
+
+        self.assertRaises(ValueError, color.ColorRGB, -1, 0, 34)
+        self.assertRaises(ValueError, color.ColorRGB, 0, -1, 34)
+        self.assertRaises(ValueError, color.ColorRGB, 0, 28, -1)
+
+    def test_colorize(self):
+        s = color.colorize('hello', color.RED, palette='ANSI')
+        self.assertIn('\033', s)
+        self.assertIn('[3', s)
+        self.assertIn('1m', s)
+
+        with self.assertRaises(ValueError):
+            color.colorize('hello', color.RED, palette='FOO')
+
+        with self.assertRaises(ValueError):
+            color.colorize('hello', color.ColorRGB(128, 0, 34), palette='ANSI')

unittests/test_logging.py

@@ -358,11 +358,10 @@ def test_logging_context_check(self):
             rlog.getlogger().error('error from context')
 
         rlog.getlogger().error('error outside context')
-
-        self.assertTrue(
-            self.found_in_logfile('random_check: error from context'))
-        self.assertTrue(
-            self.found_in_logfile('reframe: error outside context'))
+        self.assertTrue(self.found_in_logfile(
+            'random_check: %s: error from context' % sys.argv[0]))
+        self.assertTrue(self.found_in_logfile(
+            'reframe: %s: error outside context' % sys.argv[0]))
 
     def test_logging_context_error(self):
         rlog.configure_logging(self.logging_config)