color logging support

Change-Id: Ic88b41e4032d6c97e020485341d375c196a1a1c0

6 files changed, 115 insertions, 12 deletions

diff --git a/pecan/commands/serve.py b/pecan/commands/serve.py
index 0d1b14a..72a536d 100644
--- a/pecan/commands/serve.py
+++ b/pecan/commands/serve.py
@@ -2,12 +2,19 @@
 Serve command for Pecan.
 """
 from __future__ import print_function
+import logging
 import os
 import sys
 import time
 import subprocess
+from wsgiref.simple_server import WSGIRequestHandler
+
 
 from pecan.commands import BaseCommand
+from pecan import util
+
+
+logger = logging.getLogger(__name__)
 
 
 class ServeCommand(BaseCommand):
@@ -100,7 +107,12 @@ class ServeCommand(BaseCommand):
         from wsgiref.simple_server import make_server
 
         host, port = conf.server.host, int(conf.server.port)
-        srv = make_server(host, port, app)
+        srv = make_server(
+            host,
+            port,
+            app,
+            handler_class=PecanWSGIRequestHandler,
+        )
 
         print('Starting server in PID %s' % os.getpid())
 
@@ -178,3 +190,34 @@ def gunicorn_run():
             return deploy(self.cfgfname)
 
     PecanApplication("%(prog)s [OPTIONS] config.py").run()
+
+
+class PecanWSGIRequestHandler(WSGIRequestHandler, object):
+    """
+    A wsgiref request handler class that allows actual log output depending on
+    the application configuration.
+    """
+
+    def __init__(self, *args, **kwargs):
+        # We set self.path to avoid crashes in log_message() on unsupported
+        # requests (like "OPTIONS").
+        self.path = ''
+        super(PecanWSGIRequestHandler, self).__init__(*args, **kwargs)
+
+    def log_message(self, format, *args):
+        """
+        overrides the ``log_message`` method from the wsgiref server so that
+        normal logging works with whatever configuration the application has
+        been set to.
+
+        Levels are inferred from the HTTP status code, 4XX codes are treated as
+        warnings, 5XX as errors and everything else as INFO level.
+        """
+        code = args[1][0]
+        levels = {
+            '4': 'warning',
+            '5': 'error'
+        }
+
+        log_handler = getattr(logger, levels.get(code, 'info'))
+        log_handler(format % args)
diff --git a/pecan/log.py b/pecan/log.py
new file mode 100644
index 0000000..133fdf5
--- /dev/null
+++ b/pecan/log.py
@@ -0,0 +1,54 @@
+import logging
+
+from logutils.colorize import ColorizingStreamHandler
+
+
+class DefaultColorizer(ColorizingStreamHandler):
+
+    level_map = {
+        logging.DEBUG: (None, 'blue', True),
+        logging.INFO: (None, None, True),
+        logging.WARNING: (None, 'yellow', True),
+        logging.ERROR: (None, 'red', True),
+        logging.CRITICAL: (None, 'red', True),
+    }
+
+
+class ColorFormatter(logging.Formatter):
+    """
+    A very basic logging formatter that not only applies color to the
+    levels of the ouput but can also add padding to the the level names so that
+    they do not alter the visuals of logging when presented on the terminal.
+
+    The padding is provided by a convenient keyword that adds padding to the
+    ``levelname`` so that log output is easier to follow::
+
+        %(padded_color_levelname)s
+
+    Which would result in log level output that looks like::
+
+        [INFO    ]
+        [WARNING ]
+        [ERROR   ]
+        [DEBUG   ]
+        [CRITICAL]
+
+    If colored output is not supported, it falls back to non-colored output
+    without any extra settings.
+    """
+
+    def __init__(self, _logging=None, colorizer=None, *a, **kw):
+        self.logging = _logging or logging
+        self.color = colorizer or DefaultColorizer()
+        logging.Formatter.__init__(self, *a, **kw)
+
+    def format(self, record):
+        levelname = record.levelname
+        padded_level = '%-8s' % levelname
+
+        record.color_levelname = self.color.colorize(levelname, record)
+        record.padded_color_levelname = self.color.colorize(
+            padded_level,
+            record
+        )
+        return self.logging.Formatter.format(self, record)
diff --git a/pecan/scaffolds/base/config.py_tmpl b/pecan/scaffolds/base/config.py_tmpl
index 16b70f3..696cc6a 100644
--- a/pecan/scaffolds/base/config.py_tmpl
+++ b/pecan/scaffolds/base/config.py_tmpl
@@ -21,6 +21,7 @@ logging = {
     'loggers': {
         'root': {'level': 'INFO', 'handlers': ['console']},
         '${package}': {'level': 'DEBUG', 'handlers': ['console']},
+        'pecan.commands.serve': {'level': 'DEBUG', 'handlers': ['console']},
         'py.warnings': {'handlers': ['console']},
         '__force_dict__': True
     },
@@ -28,13 +29,19 @@ logging = {
         'console': {
             'level': 'DEBUG',
             'class': 'logging.StreamHandler',
-            'formatter': 'simple'
+            'formatter': 'color'
         }
     },
     'formatters': {
         'simple': {
             'format': ('%(asctime)s %(levelname)-5.5s [%(name)s]'
                        '[%(threadName)s] %(message)s')
+        },
+        'color': {
+            '()': 'pecan.log.ColorFormatter',
+            'format': ('%(asctime)s [%(padded_color_levelname)s] [%(name)s]'
+                       '[%(threadName)s] %(message)s'),
+        '__force_dict__': True
         }
     }
 }
diff --git a/pecan/scaffolds/rest-api/config.py_tmpl b/pecan/scaffolds/rest-api/config.py_tmpl
index bd4d29d..b0b3839 100644
--- a/pecan/scaffolds/rest-api/config.py_tmpl
+++ b/pecan/scaffolds/rest-api/config.py_tmpl
@@ -15,6 +15,7 @@ logging = {
     'loggers': {
         'root': {'level': 'INFO', 'handlers': ['console']},
         '${package}': {'level': 'DEBUG', 'handlers': ['console']},
+        'pecan.commands.serve': {'level': 'DEBUG', 'handlers': ['console']},
         'py.warnings': {'handlers': ['console']},
         '__force_dict__': True
     },
@@ -22,13 +23,19 @@ logging = {
         'console': {
             'level': 'DEBUG',
             'class': 'logging.StreamHandler',
-            'formatter': 'simple'
+            'formatter': 'color'
         }
     },
     'formatters': {
         'simple': {
             'format': ('%(asctime)s %(levelname)-5.5s [%(name)s]'
                        '[%(threadName)s] %(message)s')
+        },
+        'color': {
+            '()': 'pecan.log.ColorFormatter',
+            'format': ('%(asctime)s [%(padded_color_levelname)s] [%(name)s]'
+                       '[%(threadName)s] %(message)s'),
+        '__force_dict__': True
         }
     }
 }
diff --git a/requirements.txt b/requirements.txt
index 9205775..d38259b 100644
--- a/requirements.txt
+++ b/requirements.txt
@@ -2,3 +2,4 @@ WebOb>=1.2dev
 Mako>=0.4.0
 WebTest>=1.3.1
 six
+logutils>=0.3
diff --git a/setup.py b/setup.py
index e32f5ad..468c1ef 100644
--- a/setup.py
+++ b/setup.py
@@ -23,15 +23,6 @@ except:
         requirements.append("simplejson >= 2.1.1")
 
 try:
-    from logging.config import dictConfig  # noqa
-except ImportError:
-    #
-    # This was introduced in Python 2.7 - the logutils package contains
-    # a backported replacement for 2.6
-    #
-    requirements.append('logutils')
-
-try:
     import argparse  # noqa
 except:
     #