diff options
| -rw-r--r-- | openstack/common/exception.py | 18 | ||||
| -rw-r--r-- | openstack/common/log.py | 456 | ||||
| -rw-r--r-- | openstack/common/notifier/__init__.py | 14 | ||||
| -rw-r--r-- | openstack/common/notifier/api.py | 142 | ||||
| -rw-r--r-- | openstack/common/notifier/list_notifier.py | 116 | ||||
| -rw-r--r-- | openstack/common/notifier/log_notifier.py | 34 | ||||
| -rw-r--r-- | openstack/common/notifier/no_op_notifier.py | 19 | ||||
| -rw-r--r-- | openstack/common/notifier/rabbit_notifier.py | 45 | ||||
| -rw-r--r-- | openstack/common/notifier/test_notifier.py | 22 | ||||
| -rw-r--r-- | tests/unit/notifier/__init__.py | 14 | ||||
| -rw-r--r-- | tests/unit/notifier/test_list_notifier.py | 135 | ||||
| -rw-r--r-- | tests/unit/test_log.py | 218 | ||||
| -rw-r--r-- | tests/unit/test_notifier.py | 186 |
13 files changed, 1419 insertions, 0 deletions
diff --git a/openstack/common/exception.py b/openstack/common/exception.py index ba32da5..e8ea110 100644 --- a/openstack/common/exception.py +++ b/openstack/common/exception.py @@ -19,6 +19,7 @@ Exceptions common to OpenStack projects """ +import itertools import logging @@ -145,3 +146,20 @@ class MalformedRequestBody(OpenstackException): class InvalidContentType(OpenstackException): message = "Invalid content type %(content_type)s" + + +def get_context_from_function_and_args(function, args, kwargs): + """Find an arg of type RequestContext and return it. + + This is useful in a couple of decorators where we don't + know much about the function we're wrapping. + """ + + # import here to avoid circularity: + from openstack.common import context + + for arg in itertools.chain(kwargs.values(), args): + if isinstance(arg, context.RequestContext): + return arg + + return None diff --git a/openstack/common/log.py b/openstack/common/log.py new file mode 100644 index 0000000..bd2724f --- /dev/null +++ b/openstack/common/log.py @@ -0,0 +1,456 @@ +# vim: tabstop=4 shiftwidth=4 softtabstop=4 + +# Copyright 2011 OpenStack LLC. +# 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. + +"""Openstack 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. Additionally, an instance uuid +may be passed as part of the log message, which is intended to make it easier +for admins to find messages related to a specific instance. + +It also allows setting of formatting information through conf. + +""" + +import cStringIO +import inspect +import itertools +import json +import logging +import logging.config +import logging.handlers +import os +import stat +import sys +import traceback + +from openstack.common import cfg +from openstack.common import local +from openstack.common import notifier + + +log_opts = [ + cfg.StrOpt('logging_context_format_string', + default='%(asctime)s %(levelname)s %(name)s [%(request_id)s ' + '%(user_id)s %(project_id)s] %(instance)s' + '%(message)s', + help='format string to use for log messages with context'), + cfg.StrOpt('logging_default_format_string', + default='%(asctime)s %(levelname)s %(name)s [-] %(instance)s' + '%(message)s', + help='format string to use for log messages without context'), + cfg.StrOpt('logging_debug_format_suffix', + default='from (pid=%(process)d) %(funcName)s ' + '%(pathname)s:%(lineno)d', + help='data to append to log format when level is DEBUG'), + cfg.StrOpt('logging_exception_prefix', + default='%(asctime)s TRACE %(name)s %(instance)s', + help='prefix each line of exception output with this format'), + cfg.ListOpt('default_log_levels', + default=[ + 'amqplib=WARN', + 'sqlalchemy=WARN', + 'boto=WARN', + 'suds=INFO', + 'keystone=INFO', + 'eventlet.wsgi.server=WARN' + ], + help='list of logger=LEVEL pairs'), + cfg.BoolOpt('publish_errors', + default=False, + help='publish error events'), + + # NOTE(mikal): there are two options here because sometimes we are handed + # a full instance (and could include more information), and other times we + # are just handed a UUID for the instance. + cfg.StrOpt('instance_format', + default='[instance: %(uuid)s] ', + help='If an instance is passed with the log message, format ' + 'it like this'), + cfg.StrOpt('instance_uuid_format', + default='[instance: %(uuid)s] ', + help='If an instance UUID is passed with the log message, ' + 'format it like this'), + ] + + +generic_log_opts = [ + cfg.StrOpt('logdir', + default=None, + help='Log output to a per-service log file in named directory'), + cfg.StrOpt('logfile', + default=None, + help='Log output to a named file'), + cfg.BoolOpt('use_stderr', + default=True, + help='Log output to standard error'), + cfg.StrOpt('logfile_mode', + default='0644', + help='Default file mode used when creating log files'), + ] + + +CONF = cfg.CONF +CONF.register_opts(generic_log_opts) +CONF.register_opts(log_opts) + +# our new audit level +# NOTE(jkoelker) Since we synthesized an audit level, make the logging +# module aware of it so it acts like other levels. +logging.AUDIT = logging.INFO + 1 +logging.addLevelName(logging.AUDIT, 'AUDIT') + + +try: + NullHandler = logging.NullHandler +except AttributeError: # NOTE(jkoelker) NullHandler added in Python 2.7 + class NullHandler(logging.Handler): + def handle(self, record): + pass + + def emit(self, record): + pass + + def createLock(self): + self.lock = None + + +def _dictify_context(context): + if context is None: + return None + if not isinstance(context, dict) and getattr(context, 'to_dict', None): + context = context.to_dict() + return context + + +def _get_binary_name(): + return os.path.basename(inspect.stack()[-1][1]) + + +def _get_log_file_path(binary=None): + logfile = CONF.log_file or CONF.logfile + logdir = CONF.log_dir or CONF.logdir + + if logfile and not logdir: + return logfile + + if logfile and logdir: + return os.path.join(logdir, logfile) + + if logdir: + binary = binary or _get_binary_name() + return '%s.log' % (os.path.join(logdir, binary),) + + +class ContextAdapter(logging.LoggerAdapter): + warn = logging.LoggerAdapter.warning + + def __init__(self, logger, project_name, version_string): + self.logger = logger + self.project = project_name + self.version = version_string + + def audit(self, msg, *args, **kwargs): + self.log(logging.AUDIT, msg, *args, **kwargs) + + def process(self, msg, kwargs): + if 'extra' not in kwargs: + kwargs['extra'] = {} + extra = kwargs['extra'] + + context = kwargs.pop('context', None) + if not context: + context = getattr(local.store, 'context', None) + if context: + extra.update(_dictify_context(context)) + + instance = kwargs.pop('instance', None) + instance_extra = '' + if instance: + instance_extra = CONF.instance_format % instance + else: + instance_uuid = kwargs.pop('instance_uuid', None) + if instance_uuid: + instance_extra = (CONF.instance_uuid_format + % {'uuid': instance_uuid}) + extra.update({'instance': instance_extra}) + + extra.update({"project": self.project}) + extra.update({"version": self.version}) + extra['extra'] = extra.copy() + return msg, kwargs + + +class JSONFormatter(logging.Formatter): + def __init__(self, fmt=None, datefmt=None): + # NOTE(jkoelker) we ignore the fmt argument, but its still there + # since logging.config.fileConfig passes it. + self.datefmt = datefmt + + def formatException(self, ei, strip_newlines=True): + lines = traceback.format_exception(*ei) + if strip_newlines: + lines = [itertools.ifilter(lambda x: x, + line.rstrip().splitlines()) + for line in lines] + lines = list(itertools.chain(*lines)) + return lines + + def format(self, record): + message = {'message': record.getMessage(), + 'asctime': self.formatTime(record, self.datefmt), + 'name': record.name, + 'msg': record.msg, + 'args': record.args, + 'levelname': record.levelname, + 'levelno': record.levelno, + 'pathname': record.pathname, + 'filename': record.filename, + 'module': record.module, + 'lineno': record.lineno, + 'funcname': record.funcName, + 'created': record.created, + 'msecs': record.msecs, + 'relative_created': record.relativeCreated, + 'thread': record.thread, + 'thread_name': record.threadName, + 'process_name': record.processName, + 'process': record.process, + 'traceback': None} + + if hasattr(record, 'extra'): + message['extra'] = record.extra + + if record.exc_info: + message['traceback'] = self.formatException(record.exc_info) + + return json.dumps(message) + + +class PublishErrorsHandler(logging.Handler): + def emit(self, record): + if 'list_notifier_drivers' in CONF: + if ('openstack.common.notifier.log_notifier' in + CONF.list_notifier_drivers): + return + notifier.api.notify(None, 'error.publisher', + 'error_notification', + notifier.api.ERROR, + dict(error=record.msg)) + + +def handle_exception(type, value, tb): + extra = {} + if CONF.verbose: + extra['exc_info'] = (type, value, tb) + getLogger().critical(str(value), **extra) + + +def setup(product_name): + """Setup logging.""" + sys.excepthook = handle_exception + + if CONF.log_config: + try: + logging.config.fileConfig(CONF.log_config) + except Exception: + traceback.print_exc() + raise + else: + _setup_logging_from_conf(product_name) + + +def _find_facility_from_conf(): + facility_names = logging.handlers.SysLogHandler.facility_names + facility = getattr(logging.handlers.SysLogHandler, + CONF.syslog_log_facility, + None) + + if facility is None and CONF.syslog_log_facility in facility_names: + facility = facility_names.get(CONF.syslog_log_facility) + + if facility is None: + valid_facilities = facility_names.keys() + consts = ['LOG_AUTH', 'LOG_AUTHPRIV', 'LOG_CRON', 'LOG_DAEMON', + 'LOG_FTP', 'LOG_KERN', 'LOG_LPR', 'LOG_MAIL', 'LOG_NEWS', + 'LOG_AUTH', 'LOG_SYSLOG', 'LOG_USER', 'LOG_UUCP', + 'LOG_LOCAL0', 'LOG_LOCAL1', 'LOG_LOCAL2', 'LOG_LOCAL3', + 'LOG_LOCAL4', 'LOG_LOCAL5', 'LOG_LOCAL6', 'LOG_LOCAL7'] + valid_facilities.extend(consts) + raise TypeError(_('syslog facility must be one of: %s') % + ', '.join("'%s'" % fac + for fac in valid_facilities)) + + return facility + + +def _setup_logging_from_conf(product_name): + log_root = getLogger(product_name).logger + for handler in log_root.handlers: + log_root.removeHandler(handler) + + if CONF.use_syslog: + facility = _find_facility_from_conf() + syslog = logging.handlers.SysLogHandler(address='/dev/log', + facility=facility) + log_root.addHandler(syslog) + + logpath = _get_log_file_path() + if logpath: + filelog = logging.handlers.WatchedFileHandler(logpath) + log_root.addHandler(filelog) + + mode = int(CONF.logfile_mode, 8) + st = os.stat(logpath) + if st.st_mode != (stat.S_IFREG | mode): + os.chmod(logpath, mode) + + if CONF.use_stderr: + streamlog = ColorHandler() + log_root.addHandler(streamlog) + + elif not CONF.log_file: + streamlog = logging.StreamHandler(stream=sys.stdout) + log_root.addHandler(streamlog) + + if CONF.publish_errors: + log_root.addHandler(PublishErrorsHandler(logging.ERROR)) + + for handler in log_root.handlers: + datefmt = CONF.log_date_format + if CONF.log_format: + handler.setFormatter(logging.Formatter(fmt=CONF.log_format, + datefmt=datefmt)) + handler.setFormatter(LegacyFormatter(datefmt=datefmt)) + + if CONF.verbose or CONF.debug: + log_root.setLevel(logging.DEBUG) + else: + log_root.setLevel(logging.INFO) + + level = logging.NOTSET + for pair in CONF.default_log_levels: + mod, _sep, level_name = pair.partition('=') + level = logging.getLevelName(level_name) + logger = logging.getLogger(mod) + logger.setLevel(level) + for handler in log_root.handlers: + logger.addHandler(handler) + + # NOTE(jkoelker) Clear the handlers for the root logger that was setup + # by basicConfig in nova/__init__.py and install the + # NullHandler. + root = logging.getLogger() + for handler in root.handlers: + root.removeHandler(handler) + handler = NullHandler() + handler.setFormatter(logging.Formatter()) + root.addHandler(handler) + + +_loggers = {} + + +def getLogger(name='unknown', version='unknown'): + if name not in _loggers: + _loggers[name] = ContextAdapter(logging.getLogger(name), + name, + version) + return _loggers[name] + + +class WritableLogger(object): + """A thin wrapper that responds to `write` and logs.""" + + def __init__(self, logger, level=logging.INFO): + self.logger = logger + self.level = level + + def write(self, msg): + self.logger.log(self.level, msg) + + +class LegacyFormatter(logging.Formatter): + """A context.RequestContext aware formatter configured through flags. + + The flags used to set format strings are: logging_context_format_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 'instance' not in record.__dict__: + record.__dict__['instance'] = '' + + if record.__dict__.get('request_id', None): + self._fmt = CONF.logging_context_format_string + else: + self._fmt = CONF.logging_default_format_string + + if (record.levelno == logging.DEBUG and + CONF.logging_debug_format_suffix): + self._fmt += " " + CONF.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 CONF.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() + + if CONF.logging_exception_prefix.find('%(asctime)') != -1: + record.asctime = self.formatTime(record, self.datefmt) + + formatted_lines = [] + for line in lines: + pl = CONF.logging_exception_prefix % record.__dict__ + fl = '%s%s' % (pl, line) + formatted_lines.append(fl) + return '\n'.join(formatted_lines) + + +class ColorHandler(logging.StreamHandler): + LEVEL_COLORS = { + logging.DEBUG: '\033[00;32m', # GREEN + logging.INFO: '\033[00;36m', # CYAN + logging.AUDIT: '\033[01;36m', # BOLD CYAN + logging.WARN: '\033[01;33m', # BOLD YELLOW + logging.ERROR: '\033[01;31m', # BOLD RED + logging.CRITICAL: '\033[01;31m', # BOLD RED + } + + def format(self, record): + record.color = self.LEVEL_COLORS[record.levelno] + return logging.StreamHandler.format(self, record) diff --git a/openstack/common/notifier/__init__.py b/openstack/common/notifier/__init__.py new file mode 100644 index 0000000..482d54e --- /dev/null +++ b/openstack/common/notifier/__init__.py @@ -0,0 +1,14 @@ +# Copyright 2011 OpenStack LLC. +# 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. diff --git a/openstack/common/notifier/api.py b/openstack/common/notifier/api.py new file mode 100644 index 0000000..6a46cd2 --- /dev/null +++ b/openstack/common/notifier/api.py @@ -0,0 +1,142 @@ +# Copyright 2011 OpenStack LLC. +# 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. + +import inspect +import uuid + +from openstack.common import cfg +from openstack.common import exception +from openstack.common import importutils +from openstack.common import jsonutils +from openstack.common import log as logging +from openstack.common import timeutils +from openstack.common import utils + + +LOG = logging.getLogger(__name__) + +notifier_opts = [ + cfg.StrOpt('notification_driver', + default='openstack.common.notifier.no_op_notifier', + help='Default driver for sending notifications'), + cfg.StrOpt('default_notification_level', + default='INFO', + help='Default notification level for outgoing notifications'), + cfg.StrOpt('default_publisher_id', + default='$host', + help='Default publisher_id for outgoing notifications'), + ] + +CONF = cfg.CONF +CONF.register_opts(notifier_opts) + +WARN = 'WARN' +INFO = 'INFO' +ERROR = 'ERROR' +CRITICAL = 'CRITICAL' +DEBUG = 'DEBUG' + +log_levels = (DEBUG, WARN, INFO, ERROR, CRITICAL) + + +class BadPriorityException(Exception): + pass + + +def notify_decorator(name, fn): + """ decorator for notify which is used from utils.monkey_patch() + + :param name: name of the function + :param function: - object of the function + :returns: function -- decorated function + + """ + def wrapped_func(*args, **kwarg): + body = {} + body['args'] = [] + body['kwarg'] = {} + for arg in args: + body['args'].append(arg) + for key in kwarg: + body['kwarg'][key] = kwarg[key] + + context = exception.get_context_from_function_and_args(fn, args, kwarg) + notify(context, + CONF.default_publisher_id, + name, + CONF.default_notification_level, + body) + return fn(*args, **kwarg) + return wrapped_func + + +def publisher_id(service, host=None): + if not host: + host = CONF.host + return "%s.%s" % (service, host) + + +def notify(context, publisher_id, event_type, priority, payload): + """Sends a notification using the specified driver + + :param publisher_id: the source worker_type.host of the message + :param event_type: the literal type of event (ex. Instance Creation) + :param priority: patterned after the enumeration of Python logging + levels in the set (DEBUG, WARN, INFO, ERROR, CRITICAL) + :param payload: A python dictionary of attributes + + Outgoing message format includes the above parameters, and appends the + following: + + message_id + a UUID representing the id for this notification + + timestamp + the GMT timestamp the notification was sent at + + The composite message will be constructed as a dictionary of the above + attributes, which will then be sent via the transport mechanism defined + by the driver. + + Message example:: + + {'message_id': str(uuid.uuid4()), + 'publisher_id': 'compute.host1', + 'timestamp': timeutils.utcnow(), + 'priority': 'WARN', + 'event_type': 'compute.create_instance', + 'payload': {'instance_id': 12, ... }} + + """ + if priority not in log_levels: + raise BadPriorityException( + _('%s not in valid priorities') % priority) + + # Ensure everything is JSON serializable. + payload = jsonutils.to_primitive(payload, convert_instances=True) + + driver = importutils.import_module(CONF.notification_driver) + msg = dict(message_id=str(uuid.uuid4()), + publisher_id=publisher_id, + event_type=event_type, + priority=priority, + payload=payload, + timestamp=str(timeutils.utcnow())) + try: + driver.notify(context, msg) + except Exception, e: + LOG.exception(_("Problem '%(e)s' attempting to " + "send to notification system. Payload=%(payload)s") % + locals()) diff --git a/openstack/common/notifier/list_notifier.py b/openstack/common/notifier/list_notifier.py new file mode 100644 index 0000000..cd7e6d5 --- /dev/null +++ b/openstack/common/notifier/list_notifier.py @@ -0,0 +1,116 @@ +# Copyright 2011 OpenStack LLC. +# 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. + +from openstack.common import cfg +from openstack.common import importutils +from openstack.common import log as logging + + +list_notifier_drivers_opt = cfg.MultiStrOpt('list_notifier_drivers', + default=['openstack.common.notifier.no_op_notifier'], + help='List of drivers to send notifications') + +CONF = cfg.CONF +CONF.register_opt(list_notifier_drivers_opt) + +LOG = logging.getLogger(__name__) + +drivers = None + + +class ImportFailureNotifier(object): + """Noisily re-raises some exception over-and-over when notify is called.""" + + def __init__(self, exception): + self.exception = exception + + def notify(self, context, message): + raise self.exception + + +def _get_drivers(): + """Instantiates and returns drivers based on the flag values.""" + global drivers + if drivers is None: + drivers = [] + for notification_driver in CONF.list_notifier_drivers: + try: + drivers.append(importutils.import_module(notification_driver)) + except ImportError as e: + drivers.append(ImportFailureNotifier(e)) + return drivers + + +def add_driver(notification_driver): + """Add a notification driver at runtime.""" + # Make sure the driver list is initialized. + _get_drivers() + if isinstance(notification_driver, basestring): + # Load and add + try: + drivers.append(importutils.import_module(notification_driver)) + except ImportError as e: + drivers.append(ImportFailureNotifier(e)) + else: + # Driver is already loaded; just add the object. + drivers.append(notification_driver) + + +def _object_name(obj): + name = [] + if hasattr(obj, '__module__'): + name.append(obj.__module__) + if hasattr(obj, '__name__'): + name.append(obj.__name__) + else: + name.append(obj.__class__.__name__) + return '.'.join(name) + + +def remove_driver(notification_driver): + """Remove a notification driver at runtime.""" + # Make sure the driver list is initialized. + _get_drivers() + removed = False + if notification_driver in drivers: + # We're removing an object. Easy. + drivers.remove(notification_driver) + removed = True + else: + # We're removing a driver by name. Search for it. + for driver in drivers: + if _object_name(driver) == notification_driver: + drivers.remove(driver) + removed = True + + if not removed: + raise ValueError("Cannot remove; %s is not in list" % + notification_driver) + + +def notify(context, message): + """Passes notification to multiple notifiers in a list.""" + for driver in _get_drivers(): + try: + driver.notify(context, message) + except Exception as e: + LOG.exception(_("Problem '%(e)s' attempting to send to " + "notification driver %(driver)s."), locals()) + + +def _reset_drivers(): + """Used by unit tests to reset the drivers.""" + global drivers + drivers = None diff --git a/openstack/common/notifier/log_notifier.py b/openstack/common/notifier/log_notifier.py new file mode 100644 index 0000000..594fd3e --- /dev/null +++ b/openstack/common/notifier/log_notifier.py @@ -0,0 +1,34 @@ +# Copyright 2011 OpenStack LLC. +# 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. + +import json + +from openstack.common import cfg +from openstack.common import log as logging + + +CONF = cfg.CONF + + +def notify(_context, message): + """Notifies the recipient of the desired event given the model. + Log notifications using openstack's default logging system""" + + priority = message.get('priority', + CONF.default_notification_level) + priority = priority.lower() + logger = logging.getLogger( + 'openstack.common.notification.%s' % message['event_type']) + getattr(logger, priority)(json.dumps(message)) diff --git a/openstack/common/notifier/no_op_notifier.py b/openstack/common/notifier/no_op_notifier.py new file mode 100644 index 0000000..ee1ddbd --- /dev/null +++ b/openstack/common/notifier/no_op_notifier.py @@ -0,0 +1,19 @@ +# Copyright 2011 OpenStack LLC. +# 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. + + +def notify(_context, message): + """Notifies the recipient of the desired event given the model""" + pass diff --git a/openstack/common/notifier/rabbit_notifier.py b/openstack/common/notifier/rabbit_notifier.py new file mode 100644 index 0000000..14f0f91 --- /dev/null +++ b/openstack/common/notifier/rabbit_notifier.py @@ -0,0 +1,45 @@ +# Copyright 2011 OpenStack LLC. +# 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. + + +from openstack.common import cfg +from openstack.common import context as req_context +from openstack.common import log as logging +from openstack.common import rpc + +LOG = logging.getLogger(__name__) + +notification_topic_opt = cfg.ListOpt('notification_topics', + default=['notifications', ], + help='AMQP topic used for openstack notifications') + +CONF = cfg.CONF +CONF.register_opt(notification_topic_opt) + + +def notify(context, message): + """Sends a notification to the RabbitMQ""" + if not context: + context = req_context.get_admin_context() + priority = message.get('priority', + CONF.default_notification_level) + priority = priority.lower() + for topic in CONF.notification_topics: + topic = '%s.%s' % (topic, priority) + try: + rpc.notify(context, topic, message) + except Exception, e: + LOG.exception(_("Could not send notification to %(topic)s. " + "Payload=%(message)s"), locals()) diff --git a/openstack/common/notifier/test_notifier.py b/openstack/common/notifier/test_notifier.py new file mode 100644 index 0000000..5e34880 --- /dev/null +++ b/openstack/common/notifier/test_notifier.py @@ -0,0 +1,22 @@ +# Copyright 2011 OpenStack LLC. +# 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. + + +NOTIFICATIONS = [] + + +def notify(_context, message): + """Test notifier, stores notifications in memory for unittests.""" + NOTIFICATIONS.append(message) diff --git a/tests/unit/notifier/__init__.py b/tests/unit/notifier/__init__.py new file mode 100644 index 0000000..482d54e --- /dev/null +++ b/tests/unit/notifier/__init__.py @@ -0,0 +1,14 @@ +# Copyright 2011 OpenStack LLC. +# 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. diff --git a/tests/unit/notifier/test_list_notifier.py b/tests/unit/notifier/test_list_notifier.py new file mode 100644 index 0000000..5708a43 --- /dev/null +++ b/tests/unit/notifier/test_list_notifier.py @@ -0,0 +1,135 @@ +# Copyright 2011 OpenStack LLC. +# 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. + +from openstack.common import log as logging +from openstack.common.notifier import api +from openstack.common.notifier import list_notifier +from openstack.common.notifier import log_notifier +from openstack.common.notifier import no_op_notifier +from tests import utils as test_utils + + +class SimpleNotifier(object): + def __init__(self): + self.notified = False + + def notify(self, *args): + self.notified = True + + +class NotifierListTestCase(test_utils.BaseTestCase): + """Test case for notifications""" + + def setUp(self): + super(NotifierListTestCase, self).setUp() + list_notifier._reset_drivers() + # Mock log to add one to exception_count when log.exception is called + + def mock_exception(cls, *args): + self.exception_count += 1 + + self.exception_count = 0 + list_notifier_log = logging.getLogger( + 'openstack.common.notifier.list_notifier') + self.stubs.Set(list_notifier_log, "exception", mock_exception) + # Mock no_op notifier to add one to notify_count when called. + + def mock_notify(cls, *args): + self.notify_count += 1 + + self.notify_count = 0 + self.stubs.Set(no_op_notifier, 'notify', mock_notify) + # Mock log_notifier to raise RuntimeError when called. + + def mock_notify2(cls, *args): + raise RuntimeError("Bad notifier.") + + self.stubs.Set(log_notifier, 'notify', mock_notify2) + + def tearDown(self): + list_notifier._reset_drivers() + super(NotifierListTestCase, self).tearDown() + + def test_send_notifications_successfully(self): + self.config(notification_driver='openstack.common.' + 'notifier.list_notifier', + list_notifier_drivers=[ + 'openstack.common.notifier.no_op_notifier', + 'openstack.common.notifier.no_op_notifier']) + api.notify('contextarg', 'publisher_id', 'event_type', + api.WARN, dict(a=3)) + self.assertEqual(self.notify_count, 2) + self.assertEqual(self.exception_count, 0) + + def test_send_notifications_with_errors(self): + + self.config(notification_driver='openstack.common.' + 'notifier.list_notifier', + list_notifier_drivers=[ + 'openstack.common.notifier.no_op_notifier', + 'openstack.common.notifier.log_notifier']) + api.notify('contextarg', 'publisher_id', + 'event_type', api.WARN, dict(a=3)) + self.assertEqual(self.notify_count, 1) + self.assertEqual(self.exception_count, 1) + + def test_when_driver_fails_to_import(self): + self.config(notification_driver='openstack.common.' + 'notifier.list_notifier', + list_notifier_drivers=[ + 'openstack.common.notifier.no_op_notifier', + 'openstack.common.notifier.logo_notifier', + 'fdsjgsdfhjkhgsfkj']) + api.notify('contextarg', 'publisher_id', + 'event_type', api.WARN, dict(a=3)) + self.assertEqual(self.exception_count, 2) + self.assertEqual(self.notify_count, 1) + + def test_adding_and_removing_notifier_object(self): + self.notifier_object = SimpleNotifier() + self.config(notification_driver='openstack.common.' + 'notifier.list_notifier', + list_notifier_drivers=[ + 'openstack.common.notifier.no_op_notifier']) + + list_notifier.add_driver(self.notifier_object) + api.notify(None, 'publisher_id', 'event_type', + api.WARN, dict(a=3)) + self.assertEqual(self.notify_count, 1) + self.assertTrue(self.notifier_object.notified) + + self.notifier_object.notified = False + list_notifier.remove_driver(self.notifier_object) + + api.notify(None, 'publisher_id', 'event_type', + api.WARN, dict(a=3)) + self.assertEqual(self.notify_count, 2) + self.assertFalse(self.notifier_object.notified) + + def test_adding_and_removing_notifier_module(self): + self.config(notification_driver='openstack.common.' + 'notifier.list_notifier', + list_notifier_drivers=[]) + + list_notifier.add_driver('openstack.common.notifier.no_op_notifier') + api.notify(None, 'publisher_id', 'event_type', + api.WARN, dict(a=3)) + self.assertEqual(self.notify_count, 1) + + list_notifier.remove_driver('openstack.common.notifier.no_op_notifier') + + api.notify(None, 'publisher_id', 'event_type', + api.WARN, dict(a=3)) + self.assertEqual(self.notify_count, 1) diff --git a/tests/unit/test_log.py b/tests/unit/test_log.py new file mode 100644 index 0000000..f417db5 --- /dev/null +++ b/tests/unit/test_log.py @@ -0,0 +1,218 @@ +import cStringIO +import json +import logging +import sys + +from openstack.common import context +from openstack.common import cfg +from openstack.common import log +from openstack.common.notifier import api as notifier +from openstack.common.notifier import list_notifier +from tests import utils as test_utils + +CONF = cfg.CONF + + +def _fake_context(): + return context.RequestContext(1, 1) + + +class LoggerTestCase(test_utils.BaseTestCase): + def setUp(self): + super(LoggerTestCase, self).setUp() + self.log = log.getLogger() + + def test_handlers_have_legacy_formatter(self): + formatters = [] + for h in self.log.logger.handlers: + f = h.formatter + if isinstance(f, log.LegacyFormatter): + formatters.append(f) + self.assert_(formatters) + self.assertEqual(len(formatters), len(self.log.logger.handlers)) + + def test_handles_context_kwarg(self): + self.log.info("foo", context=_fake_context()) + self.assert_(True) # didn't raise exception + + def test_audit_handles_context_arg(self): + self.log.audit("foo", context=_fake_context()) + self.assert_(True) # didn't raise exception + + def test_will_be_verbose_if_verbose_flag_set(self): + self.config(verbose=True) + log.setup() + self.assertEqual(logging.DEBUG, self.log.logger.getEffectiveLevel()) + + def test_will_not_be_verbose_if_verbose_flag_not_set(self): + self.config(verbose=False) + log.setup() + self.assertEqual(logging.INFO, self.log.logger.getEffectiveLevel()) + + def test_no_logging_via_module(self): + for func in ('critical', 'error', 'exception', 'warning', 'warn', + 'info', 'debug', 'log', 'audit'): + self.assertRaises(AttributeError, getattr, log, func) + + +class LogHandlerTestCase(test_utils.BaseTestCase): + def test_log_path_logdir(self): + self.config(logdir='/some/path', logfile=None) + self.assertEquals(log._get_log_file_path(binary='foo-bar'), + '/some/path/foo-bar.log') + + def test_log_path_logfile(self): + self.config(logfile='/some/path/foo-bar.log') + self.assertEquals(log._get_log_file_path(binary='foo-bar'), + '/some/path/foo-bar.log') + + def test_log_path_none(self): + self.config(logdir=None, logfile=None) + self.assertTrue(log._get_log_file_path(binary='foo-bar') is None) + + def test_log_path_logfile_overrides_logdir(self): + self.config(logdir='/some/other/path', + logfile='/some/path/foo-bar.log') + self.assertEquals(log._get_log_file_path(binary='foo-bar'), + '/some/path/foo-bar.log') + + +class PublishErrorsHandlerTestCase(test_utils.BaseTestCase): + """Tests for log.PublishErrorsHandler""" + def setUp(self): + super(PublishErrorsHandlerTestCase, self).setUp() + self.publiserrorshandler = log.PublishErrorsHandler(logging.ERROR) + + def test_emit_cfg_list_notifier_drivers_in_flags(self): + self.stub_flg = False + + def fake_notifier(*args, **kwargs): + self.stub_flg = True + + self.stubs.Set(notifier, 'notify', fake_notifier) + logrecord = logging.LogRecord('name', 'WARN', '/tmp', 1, + 'Message', None, None) + self.publiserrorshandler.emit(logrecord) + self.assertTrue(self.stub_flg) + + def test_emit_cfg_log_notifier_in_list_notifier_drivers(self): + self.config(list_notifier_drivers=[ + 'openstack.common.notifier.rabbit_notifier', + 'openstack.common.notifier.log_notifier']) + self.stub_flg = True + + def fake_notifier(*args, **kwargs): + self.stub_flg = False + + self.stubs.Set(notifier, 'notify', fake_notifier) + logrecord = logging.LogRecord('name', 'WARN', '/tmp', 1, + 'Message', None, None) + self.publiserrorshandler.emit(logrecord) + self.assertTrue(self.stub_flg) + + +class LoggerTestCase(test_utils.BaseTestCase): + def setUp(self): + super(LoggerTestCase, self).setUp() + levels = CONF.default_log_levels + levels.append("nova-test=AUDIT") + self.config(default_log_levels=levels, + verbose=True) + log.setup('testing') + self.log = log.getLogger('nova-test') + + def test_has_level_from_flags(self): + self.assertEqual(logging.AUDIT, self.log.logger.getEffectiveLevel()) + + def test_child_log_has_level_of_parent_flag(self): + l = log.getLogger('nova-test.foo') + self.assertEqual(logging.AUDIT, l.logger.getEffectiveLevel()) + + +class JSONFormatterTestCase(test_utils.BaseTestCase): + def setUp(self): + super(JSONFormatterTestCase, self).setUp() + self.log = log.getLogger('test-json') + self.stream = cStringIO.StringIO() + handler = logging.StreamHandler(self.stream) + handler.setFormatter(log.JSONFormatter()) + self.log.logger.addHandler(handler) + self.log.logger.setLevel(logging.DEBUG) + + def test_json(self): + test_msg = 'This is a %(test)s line' + test_data = {'test': 'log'} + self.log.debug(test_msg, test_data) + + data = json.loads(self.stream.getvalue()) + self.assertTrue(data) + self.assertTrue('extra' in data) + self.assertEqual('test-json', data['name']) + + self.assertEqual(test_msg % test_data, data['message']) + self.assertEqual(test_msg, data['msg']) + self.assertEqual(test_data, data['args']) + + self.assertEqual('test_log.py', data['filename']) + self.assertEqual('test_json', data['funcname']) + + self.assertEqual('DEBUG', data['levelname']) + self.assertEqual(logging.DEBUG, data['levelno']) + self.assertFalse(data['traceback']) + + def test_json_exception(self): + test_msg = 'This is %s' + test_data = 'exceptional' + try: + raise Exception('This is exceptional') + except Exception: + self.log.exception(test_msg, test_data) + + data = json.loads(self.stream.getvalue()) + self.assertTrue(data) + self.assertTrue('extra' in data) + self.assertEqual('test-json', data['name']) + + self.assertEqual(test_msg % test_data, data['message']) + self.assertEqual(test_msg, data['msg']) + self.assertEqual([test_data], data['args']) + + self.assertEqual('ERROR', data['levelname']) + self.assertEqual(logging.ERROR, data['levelno']) + self.assertTrue(data['traceback']) + + +class LegacyFormatterTestCase(test_utils.BaseTestCase): + def setUp(self): + super(LegacyFormatterTestCase, self).setUp() + self.config(logging_context_format_string="HAS CONTEXT " + "[%(request_id)s]: " + "%(message)s", + logging_default_format_string="NOCTXT: %(message)s", + logging_debug_format_suffix="--DBG") + self.log = log.getLogger() + self.stream = cStringIO.StringIO() + self.handler = logging.StreamHandler(self.stream) + self.handler.setFormatter(log.LegacyFormatter()) + self.log.logger.addHandler(self.handler) + self.level = self.log.logger.getEffectiveLevel() + self.log.logger.setLevel(logging.DEBUG) + + def tearDown(self): + self.log.logger.setLevel(self.level) + self.log.logger.removeHandler(self.handler) + super(LegacyFormatterTestCase, self).tearDown() + + def test_uncontextualized_log(self): + self.log.info("foo") + self.assertEqual("NOCTXT: foo\n", self.stream.getvalue()) + + def test_contextualized_log(self): + ctxt = _fake_context() + self.log.info("bar", context=ctxt) + expected = "HAS CONTEXT [%s]: bar\n" % ctxt.request_id + self.assertEqual(expected, self.stream.getvalue()) + + def test_debugging_log(self): + self.log.debug("baz") + self.assertEqual("NOCTXT: baz --DBG\n", self.stream.getvalue()) diff --git a/tests/unit/test_notifier.py b/tests/unit/test_notifier.py new file mode 100644 index 0000000..4e1c812 --- /dev/null +++ b/tests/unit/test_notifier.py @@ -0,0 +1,186 @@ +# Copyright 2011 OpenStack LLC. +# 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. + +from openstack.common import cfg +from openstack.common import context +from openstack.common import log +from openstack.common.notifier import api as notifier_api +from openstack.common.notifier import no_op_notifier +from openstack.common.notifier import rabbit_notifier +from openstack.common import rpc +from tests import utils as test_utils + + +ctxt = context.get_admin_context() +ctxt2 = context.get_admin_context() + + +class NotifierTestCase(test_utils.BaseTestCase): + """Test case for notifications""" + def setUp(self): + super(NotifierTestCase, self).setUp() + self.config(notification_driver='openstack.common.' + 'notifier.no_op_notifier') + self.config(default_publisher_id='publisher') + + def test_send_notification(self): + self.notify_called = False + + def mock_notify(cls, *args): + self.notify_called = True + + self.stubs.Set(no_op_notifier, 'notify', + mock_notify) + + notifier_api.notify(ctxt, 'publisher_id', 'event_type', + notifier_api.WARN, dict(a=3)) + self.assertEqual(self.notify_called, True) + + def test_verify_message_format(self): + """A test to ensure changing the message format is prohibitively + annoying""" + + def message_assert(context, message): + fields = [('publisher_id', 'publisher_id'), + ('event_type', 'event_type'), + ('priority', 'WARN'), + ('payload', dict(a=3))] + for k, v in fields: + self.assertEqual(message[k], v) + self.assertTrue(len(message['message_id']) > 0) + self.assertTrue(len(message['timestamp']) > 0) + self.assertEqual(context, ctxt) + + self.stubs.Set(no_op_notifier, 'notify', + message_assert) + notifier_api.notify(ctxt, 'publisher_id', 'event_type', + notifier_api.WARN, dict(a=3)) + + def test_send_rabbit_notification(self): + self.stubs.Set(cfg.CONF, 'notification_driver', + 'openstack.common.notifier.rabbit_notifier') + self.mock_notify = False + + def mock_notify(cls, *args): + self.mock_notify = True + + self.stubs.Set(rpc, 'notify', mock_notify) + notifier_api.notify(ctxt, 'publisher_id', 'event_type', + notifier_api.WARN, dict(a=3)) + + self.assertEqual(self.mock_notify, True) + + def test_invalid_priority(self): + self.assertRaises(notifier_api.BadPriorityException, + notifier_api.notify, ctxt, 'publisher_id', + 'event_type', 'not a priority', dict(a=3)) + + def test_rabbit_priority_queue(self): + self.stubs.Set(cfg.CONF, 'notification_driver', + 'openstack.common.notifier.rabbit_notifier') + self.stubs.Set(cfg.CONF, 'notification_topics', + ['testnotify', ]) + + self.test_topic = None + + def mock_notify(context, topic, msg): + self.test_topic = topic + + self.stubs.Set(rpc, 'notify', mock_notify) + notifier_api.notify(ctxt, 'publisher_id', + 'event_type', 'DEBUG', dict(a=3)) + self.assertEqual(self.test_topic, 'testnotify.debug') + + def test_error_notification(self): + self.stubs.Set(cfg.CONF, 'notification_driver', + 'openstack.common.notifier.rabbit_notifier') + self.stubs.Set(cfg.CONF, 'publish_errors', True) + LOG = log.getLogger('common') + log.setup(None) + msgs = [] + + def mock_notify(context, topic, data): + msgs.append(data) + + self.stubs.Set(rpc, 'notify', mock_notify) + LOG.error('foo') + self.assertEqual(1, len(msgs)) + msg = msgs[0] + self.assertEqual(msg['event_type'], 'error_notification') + self.assertEqual(msg['priority'], 'ERROR') + self.assertEqual(msg['payload']['error'], 'foo') + + def test_send_notification_by_decorator(self): + self.notify_called = False + + def example_api(arg1, arg2): + return arg1 + arg2 + + example_api = notifier_api.notify_decorator( + 'example_api', + example_api) + + def mock_notify(cls, *args): + self.notify_called = True + + self.stubs.Set(no_op_notifier, 'notify', + mock_notify) + + self.assertEqual(3, example_api(1, 2)) + self.assertEqual(self.notify_called, True) + + def test_decorator_context(self): + """Verify that the notify decorator can extract the 'context' arg.""" + self.notify_called = False + self.context_arg = None + + def example_api(arg1, arg2, context): + return arg1 + arg2 + + def example_api2(arg1, arg2, **kw): + return arg1 + arg2 + + example_api = notifier_api.notify_decorator( + 'example_api', + example_api) + + example_api2 = notifier_api.notify_decorator( + 'example_api2', + example_api2) + + def mock_notify(context, cls, _type, _priority, _payload): + self.notify_called = True + self.context_arg = context + + self.stubs.Set(notifier_api, 'notify', + mock_notify) + + # Test positional context + self.assertEqual(3, example_api(1, 2, ctxt)) + self.assertEqual(self.notify_called, True) + self.assertEqual(self.context_arg, ctxt) + + self.notify_called = False + self.context_arg = None + + # Test named context + self.assertEqual(3, example_api2(1, 2, context=ctxt2)) + self.assertEqual(self.notify_called, True) + self.assertEqual(self.context_arg, ctxt2) + + # Test missing context + self.assertEqual(3, example_api2(1, 2, bananas="delicious")) + self.assertEqual(self.notify_called, True) + self.assertEqual(self.context_arg, None) |