1 files changed, 261 insertions, 0 deletions
diff --git a/nova/log.py b/nova/log.py
new file mode 100644
index 000000000..88a961e13
--- /dev/null
+++ b/nova/log.py
@@ -0,0 +1,261 @@
+# vim: tabstop=4 shiftwidth=4 softtabstop=4
+
+# Copyright 2010 United States Government as represented by the
+# Administrator of the National Aeronautics and Space Administration.
+# All Rights Reserved.
+#
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+
+"""
+Nova logging handler.
+
+This module adds to logging functionality by adding the option to specify
+a context object when calling the various log methods.  If the context object
+is not specified, default formatting is used.
+
+It also allows setting of formatting information through flags.
+"""
+
+
+import cStringIO
+import json
+import logging
+import logging.handlers
+import traceback
+
+from nova import flags
+# TODO(todd): fix after version.py merge
+# from nova import version
+
+
+FLAGS = flags.FLAGS
+
+# TODO(todd): fix after version.py merge
+# '(%(name)s %(nova_version)s): %(levelname)s '
+flags.DEFINE_string('logging_context_format_string',
+                    '(%(name)s): %(levelname)s '
+                    '[%(request_id)s %(user)s '
+                    '%(project)s] %(message)s',
+                    'format string to use for log messages')
+
+# TODO(todd): fix after version.py merge
+# '(%(name)s %(nova_version)s): %(levelname)s [N/A] '
+flags.DEFINE_string('logging_default_format_string',
+                    '(%(name)s): %(levelname)s [N/A] '
+                    '%(message)s',
+                    'format string to use for log messages')
+
+flags.DEFINE_string('logging_debug_format_suffix',
+                    'from %(processName)s (pid=%(process)d) %(funcName)s'
+                    ' %(pathname)s:%(lineno)d',
+                    'data to append to log format when level is DEBUG')
+
+flags.DEFINE_string('logging_exception_prefix',
+                    '(%(name)s): TRACE: ',
+                    'prefix each line of exception output with this format')
+
+flags.DEFINE_list('default_log_levels',
+                  ['amqplib=WARN',
+                   'sqlalchemy=WARN',
+                   'audit=INFO'],
+                  'list of logger=LEVEL pairs')
+
+flags.DEFINE_bool('use_syslog', False, 'output to syslog')
+flags.DEFINE_string('logfile', None, 'output to named file')
+
+
+
+# A list of things we want to replicate from logging.
+# levels
+CRITICAL = logging.CRITICAL
+FATAL = logging.FATAL
+ERROR = logging.ERROR
+WARNING = logging.WARNING
+WARN = logging.WARN
+INFO = logging.INFO
+DEBUG = logging.DEBUG
+NOTSET = logging.NOTSET
+# methods
+getLogger = logging.getLogger
+debug = logging.debug
+info = logging.info
+warning = logging.warning
+warn = logging.warn
+error = logging.error
+exception = logging.exception
+critical = logging.critical
+log = logging.log
+# handlers
+StreamHandler = logging.StreamHandler
+FileHandler = logging.FileHandler
+# logging.SysLogHandler is nicer than logging.logging.handler.SysLogHandler.
+SysLogHandler = logging.handlers.SysLogHandler
+
+
+# our new audit level
+AUDIT = logging.INFO + 1
+logging.addLevelName(AUDIT, 'AUDIT')
+
+
+def _dictify_context(context):
+    if context == None:
+        return None
+    if not isinstance(context, dict) \
+    and getattr(context, 'to_dict', None):
+       context = context.to_dict()
+    return context
+
+
+def basicConfig():
+    logging.basicConfig()
+    for handler in logging.root.handlers:
+        handler.setFormatter(_formatter)
+    if FLAGS.verbose:
+        logging.root.setLevel(logging.DEBUG)
+    if FLAGS.use_syslog:
+        syslog = SysLogHandler(address='/dev/log')
+        syslog.setFormatter(_formatter)
+        logging.root.addHandler(syslog)
+    if FLAGS.logfile:
+        logfile = FileHandler(FLAGS.logfile)
+        logfile.setFormatter(_formatter)
+        logging.root.addHandler(logfile)
+
+
+class NovaLogger(logging.Logger):
+    """
+    NovaLogger manages request context and formatting.
+
+    This becomes the class that is instanciated by logging.getLogger.
+    """
+    def __init__(self, name, level=NOTSET):
+        level_name = self._get_level_from_flags(name, FLAGS)
+        level = globals()[level_name]
+        logging.Logger.__init__(self, name, level)
+
+    def _get_level_from_flags(self, name, FLAGS):
+        # if exactly "nova", or a child logger, honor the verbose flag
+        if (name == "nova" or name.startswith("nova.")) and FLAGS.verbose:
+            return 'DEBUG'
+        for pair in FLAGS.default_log_levels:
+            logger, _sep, level = pair.partition('=')
+            # NOTE(todd): if we set a.b, we want a.b.c to have the same level
+            #             (but not a.bc, so we check the dot)
+            if name == logger:
+                return level
+            if name.startswith(logger) and name[len(logger)] == '.':
+                return level
+        return 'INFO'
+
+    def _log(self, level, msg, args, exc_info=None, extra=None, context=None):
+        """Extract context from any log call"""
+        if not extra:
+            extra = {}
+        if context:
+            extra.update(_dictify_context(context))
+        # TODO(todd): fix after version.py merge
+        #extra.update({"nova_version": version.string_with_vcs()})
+        logging.Logger._log(self, level, msg, args, exc_info, extra)
+
+    def addHandler(self, handler):
+        """Each handler gets our custom formatter"""
+        handler.setFormatter(_formatter)
+        logging.Logger.addHandler(self, handler)
+
+    def audit(self, msg, *args, **kwargs):
+        """Shortcut for our AUDIT level"""
+        if self.isEnabledFor(AUDIT):
+            self._log(AUDIT, msg, args, **kwargs)
+
+    def exception(self, msg, *args, **kwargs):
+        """Logging.exception doesn't handle kwargs, so breaks context"""
+        if not kwargs.get('exc_info'):
+            kwargs['exc_info'] = 1
+        self.error(msg, *args, **kwargs)
+        # NOTE(todd): does this really go here, or in _log ?
+        extra = kwargs.get('extra')
+        if not extra:
+            return
+        env = extra.get('environment')
+        if env:
+            env = env.copy()
+            for k in env.keys():
+                if not isinstance(env[k], str):
+                    env.pop(k)
+            message = "Environment: %s" % json.dumps(env)
+            kwargs.pop('exc_info')
+            self.error(message, **kwargs)
+
+logging.setLoggerClass(NovaLogger)
+
+
+class NovaRootLogger(NovaLogger):
+    pass
+
+if not isinstance(logging.root, NovaRootLogger):
+    logging.root = NovaRootLogger("nova.root", WARNING)
+    NovaLogger.root = logging.root
+    NovaLogger.manager.root = logging.root
+
+
+class NovaFormatter(logging.Formatter):
+    """
+    A nova.context.RequestContext aware formatter configured through flags.
+
+    The flags used to set format strings are: logging_context_foramt_string
+    and logging_default_format_string.  You can also specify
+    logging_debug_format_suffix to append extra formatting if the log level is
+    debug.
+
+    For information about what variables are available for the formatter see:
+    http://docs.python.org/library/logging.html#formatter
+    """
+
+    def format(self, record):
+        """Uses contextstring if request_id is set, otherwise default"""
+        if record.__dict__.get('request_id', None):
+            self._fmt = FLAGS.logging_context_format_string
+        else:
+            self._fmt = FLAGS.logging_default_format_string
+        if record.levelno == logging.DEBUG \
+        and FLAGS.logging_debug_format_suffix:
+            self._fmt += " " + FLAGS.logging_debug_format_suffix
+        # Cache this on the record, Logger will respect our formated copy
+        if record.exc_info:
+            record.exc_text = self.formatException(record.exc_info, record)
+        return logging.Formatter.format(self, record)
+
+    def formatException(self, exc_info, record=None):
+        """Format exception output with FLAGS.logging_exception_prefix"""
+        if not record:
+            return logging.Formatter.formatException(self, exc_info)
+        stringbuffer = cStringIO.StringIO()
+        traceback.print_exception(exc_info[0], exc_info[1], exc_info[2],
+                                  None, stringbuffer)
+        lines = stringbuffer.getvalue().split("\n")
+        stringbuffer.close()
+        formatted_lines = []
+        for line in lines:
+            pl = FLAGS.logging_exception_prefix % record.__dict__
+            fl = "%s%s" % (pl, line)
+            formatted_lines.append(fl)
+        return "\n".join(formatted_lines)
+
+_formatter = NovaFormatter()
+
+
+def audit(msg, *args, **kwargs):
+    """Shortcut for logging to root log with sevrity 'AUDIT'."""
+    if len(logging.root.handlers) == 0:
+        basicConfig()
+    logging.root.log(AUDIT, msg, *args, **kwargs)