08b854f6b2
In the Cinder project restarting the volume service is problematic because it's not only in the control path but also in the data path of some operations, so restarting it to change log levels is really disruptive because it takes a long time to be done properly and it does not support Active-Active configurations yet. For this reason there's a specific API to change the log levels dynamically based on a given prefix [1], but this feature is accessing directly the `_loggers` dictionary which is not ideal. This patch adds a simple method called `get_loggers` that will return a copy of the internal `_loggers` dictionary so that the Cinder feature can be changed to use this instead. [1] https://review.openstack.org/445885 Change-Id: Ife33a5dd044a4565ad6a4d559ef9f0c108f260a3
464 lines
16 KiB
Python
464 lines
16 KiB
Python
# Copyright 2011 OpenStack Foundation.
|
|
# 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 logging
|
|
import logging.config
|
|
import logging.handlers
|
|
import os
|
|
import platform
|
|
import sys
|
|
try:
|
|
import syslog
|
|
except ImportError:
|
|
syslog = None
|
|
|
|
from oslo_config import cfg
|
|
from oslo_utils import importutils
|
|
import six
|
|
from six import moves
|
|
|
|
from oslo_log._i18n import _
|
|
from oslo_log import _options
|
|
from oslo_log import formatters
|
|
from oslo_log import handlers
|
|
|
|
CRITICAL = logging.CRITICAL
|
|
FATAL = logging.FATAL
|
|
ERROR = logging.ERROR
|
|
WARNING = logging.WARNING
|
|
WARN = logging.WARNING
|
|
INFO = logging.INFO
|
|
DEBUG = logging.DEBUG
|
|
NOTSET = logging.NOTSET
|
|
TRACE = handlers._TRACE
|
|
|
|
logging.addLevelName(TRACE, 'TRACE')
|
|
|
|
|
|
def _get_log_file_path(conf, binary=None):
|
|
logfile = conf.log_file
|
|
logdir = conf.log_dir
|
|
|
|
if logfile and not logdir:
|
|
return logfile
|
|
|
|
if logfile and logdir:
|
|
return os.path.join(logdir, logfile)
|
|
|
|
if logdir:
|
|
binary = binary or handlers._get_binary_name()
|
|
return '%s.log' % (os.path.join(logdir, binary),)
|
|
|
|
return None
|
|
|
|
|
|
def _iter_loggers():
|
|
"""Iterate on existing loggers."""
|
|
|
|
# Sadly, Logger.manager and Manager.loggerDict are not documented,
|
|
# but there is no logging public function to iterate on all loggers.
|
|
|
|
# The root logger is not part of loggerDict.
|
|
yield logging.getLogger()
|
|
|
|
manager = logging.Logger.manager
|
|
for logger in manager.loggerDict.values():
|
|
if isinstance(logger, logging.PlaceHolder):
|
|
continue
|
|
yield logger
|
|
|
|
|
|
class BaseLoggerAdapter(logging.LoggerAdapter):
|
|
|
|
warn = logging.LoggerAdapter.warning
|
|
|
|
@property
|
|
def handlers(self):
|
|
return self.logger.handlers
|
|
|
|
def trace(self, msg, *args, **kwargs):
|
|
self.log(TRACE, msg, *args, **kwargs)
|
|
|
|
|
|
class KeywordArgumentAdapter(BaseLoggerAdapter):
|
|
"""Logger adapter to add keyword arguments to log record's extra data
|
|
|
|
Keywords passed to the log call are added to the "extra"
|
|
dictionary passed to the underlying logger so they are emitted
|
|
with the log message and available to the format string.
|
|
|
|
Special keywords:
|
|
|
|
extra
|
|
An existing dictionary of extra values to be passed to the
|
|
logger. If present, the dictionary is copied and extended.
|
|
resource
|
|
A dictionary-like object containing a ``name`` key or ``type``
|
|
and ``id`` keys.
|
|
|
|
"""
|
|
|
|
def process(self, msg, kwargs):
|
|
# Make a new extra dictionary combining the values we were
|
|
# given when we were constructed and anything from kwargs.
|
|
extra = {}
|
|
extra.update(self.extra)
|
|
if 'extra' in kwargs:
|
|
extra.update(kwargs.pop('extra'))
|
|
# Move any unknown keyword arguments into the extra
|
|
# dictionary.
|
|
for name in list(kwargs.keys()):
|
|
if name == 'exc_info':
|
|
continue
|
|
extra[name] = kwargs.pop(name)
|
|
# NOTE(dhellmann): The gap between when the adapter is called
|
|
# and when the formatter needs to know what the extra values
|
|
# are is large enough that we can't get back to the original
|
|
# extra dictionary easily. We leave a hint to ourselves here
|
|
# in the form of a list of keys, which will eventually be
|
|
# attributes of the LogRecord processed by the formatter. That
|
|
# allows the formatter to know which values were original and
|
|
# which were extra, so it can treat them differently (see
|
|
# JSONFormatter for an example of this). We sort the keys so
|
|
# it is possible to write sane unit tests.
|
|
extra['extra_keys'] = list(sorted(extra.keys()))
|
|
# Place the updated extra values back into the keyword
|
|
# arguments.
|
|
kwargs['extra'] = extra
|
|
|
|
# NOTE(jdg): We would like an easy way to add resource info
|
|
# to logging, for example a header like 'volume-<uuid>'
|
|
# Turns out Nova implemented this but it's Nova specific with
|
|
# instance. Also there's resource_uuid that's been added to
|
|
# context, but again that only works for Instances, and it
|
|
# only works for contexts that have the resource id set.
|
|
resource = kwargs['extra'].get('resource', None)
|
|
if resource:
|
|
|
|
# Many OpenStack resources have a name entry in their db ref
|
|
# of the form <resource_type>-<uuid>, let's just use that if
|
|
# it's passed in
|
|
if not resource.get('name', None):
|
|
|
|
# For resources that don't have the name of the format we wish
|
|
# to use (or places where the LOG call may not have the full
|
|
# object ref, allow them to pass in a dict:
|
|
# resource={'type': volume, 'id': uuid}
|
|
|
|
resource_type = resource.get('type', None)
|
|
resource_id = resource.get('id', None)
|
|
|
|
if resource_type and resource_id:
|
|
kwargs['extra']['resource'] = ('[' + resource_type +
|
|
'-' + resource_id + '] ')
|
|
else:
|
|
# FIXME(jdg): Since the name format can be specified via conf
|
|
# entry, we may want to consider allowing this to be configured
|
|
# here as well
|
|
kwargs['extra']['resource'] = ('[' + resource.get('name', '')
|
|
+ '] ')
|
|
|
|
return msg, kwargs
|
|
|
|
|
|
def _create_logging_excepthook(product_name):
|
|
def logging_excepthook(exc_type, value, tb):
|
|
extra = {'exc_info': (exc_type, value, tb)}
|
|
getLogger(product_name).critical('Unhandled error', **extra)
|
|
return logging_excepthook
|
|
|
|
|
|
class LogConfigError(Exception):
|
|
|
|
message = _('Error loading logging config %(log_config)s: %(err_msg)s')
|
|
|
|
def __init__(self, log_config, err_msg):
|
|
self.log_config = log_config
|
|
self.err_msg = err_msg
|
|
|
|
def __str__(self):
|
|
return self.message % dict(log_config=self.log_config,
|
|
err_msg=self.err_msg)
|
|
|
|
|
|
def _load_log_config(log_config_append):
|
|
try:
|
|
if not hasattr(_load_log_config, "old_time"):
|
|
_load_log_config.old_time = 0
|
|
new_time = os.path.getmtime(log_config_append)
|
|
if _load_log_config.old_time != new_time:
|
|
# Reset all existing loggers before reloading config as fileConfig
|
|
# does not reset non-child loggers.
|
|
for logger in _iter_loggers():
|
|
logger.level = logging.NOTSET
|
|
logger.handlers = []
|
|
logger.propagate = 1
|
|
logging.config.fileConfig(log_config_append,
|
|
disable_existing_loggers=False)
|
|
_load_log_config.old_time = new_time
|
|
except (moves.configparser.Error, KeyError, os.error) as exc:
|
|
raise LogConfigError(log_config_append, six.text_type(exc))
|
|
|
|
|
|
def _mutate_hook(conf, fresh):
|
|
"""Reconfigures oslo.log according to the mutated options."""
|
|
|
|
if (None, 'debug') in fresh:
|
|
_refresh_root_level(conf.debug)
|
|
|
|
if (None, 'log-config-append') in fresh:
|
|
_load_log_config.old_time = 0
|
|
if conf.log_config_append:
|
|
_load_log_config(conf.log_config_append)
|
|
|
|
|
|
def register_options(conf):
|
|
"""Register the command line and configuration options used by oslo.log."""
|
|
|
|
# Sometimes logging occurs before logging is ready (e.g., oslo_config).
|
|
# To avoid "No handlers could be found," temporarily log to sys.stderr.
|
|
root_logger = logging.getLogger(None)
|
|
if not root_logger.handlers:
|
|
root_logger.addHandler(logging.StreamHandler())
|
|
|
|
conf.register_cli_opts(_options.common_cli_opts)
|
|
conf.register_cli_opts(_options.logging_cli_opts)
|
|
conf.register_opts(_options.generic_log_opts)
|
|
conf.register_opts(_options.log_opts)
|
|
formatters._store_global_conf(conf)
|
|
|
|
conf.register_mutate_hook(_mutate_hook)
|
|
|
|
|
|
def setup(conf, product_name, version='unknown'):
|
|
"""Setup logging for the current application."""
|
|
if conf.log_config_append:
|
|
_load_log_config(conf.log_config_append)
|
|
else:
|
|
_setup_logging_from_conf(conf, product_name, version)
|
|
sys.excepthook = _create_logging_excepthook(product_name)
|
|
|
|
|
|
def set_defaults(logging_context_format_string=None,
|
|
default_log_levels=None):
|
|
"""Set default values for the configuration options used by oslo.log."""
|
|
# Just in case the caller is not setting the
|
|
# default_log_level. This is insurance because
|
|
# we introduced the default_log_level parameter
|
|
# later in a backwards in-compatible change
|
|
if default_log_levels is not None:
|
|
cfg.set_defaults(
|
|
_options.log_opts,
|
|
default_log_levels=default_log_levels)
|
|
if logging_context_format_string is not None:
|
|
cfg.set_defaults(
|
|
_options.log_opts,
|
|
logging_context_format_string=logging_context_format_string)
|
|
|
|
|
|
def tempest_set_log_file(filename):
|
|
"""Provide an API for tempest to set the logging filename.
|
|
|
|
.. warning:: Only Tempest should use this function.
|
|
|
|
We don't want applications to set a default log file, so we don't
|
|
want this in set_defaults(). Because tempest doesn't use a
|
|
configuration file we don't have another convenient way to safely
|
|
set the log file default.
|
|
|
|
"""
|
|
cfg.set_defaults(_options.logging_cli_opts, log_file=filename)
|
|
|
|
|
|
def _find_facility(facility):
|
|
# NOTE(jd): Check the validity of facilities at run time as they differ
|
|
# depending on the OS and Python version being used.
|
|
valid_facilities = [f for f in
|
|
["LOG_KERN", "LOG_USER", "LOG_MAIL",
|
|
"LOG_DAEMON", "LOG_AUTH", "LOG_SYSLOG",
|
|
"LOG_LPR", "LOG_NEWS", "LOG_UUCP",
|
|
"LOG_CRON", "LOG_AUTHPRIV", "LOG_FTP",
|
|
"LOG_LOCAL0", "LOG_LOCAL1", "LOG_LOCAL2",
|
|
"LOG_LOCAL3", "LOG_LOCAL4", "LOG_LOCAL5",
|
|
"LOG_LOCAL6", "LOG_LOCAL7"]
|
|
if getattr(syslog, f, None)]
|
|
|
|
facility = facility.upper()
|
|
|
|
if not facility.startswith("LOG_"):
|
|
facility = "LOG_" + facility
|
|
|
|
if facility not in valid_facilities:
|
|
raise TypeError(_('syslog facility must be one of: %s') %
|
|
', '.join("'%s'" % fac
|
|
for fac in valid_facilities))
|
|
|
|
return getattr(syslog, facility)
|
|
|
|
|
|
def _refresh_root_level(debug):
|
|
"""Set the level of the root logger.
|
|
|
|
:param debug: If 'debug' is True, the level will be DEBUG.
|
|
Otherwise the level will be INFO.
|
|
"""
|
|
log_root = getLogger(None).logger
|
|
if debug:
|
|
log_root.setLevel(logging.DEBUG)
|
|
else:
|
|
log_root.setLevel(logging.INFO)
|
|
|
|
|
|
def _setup_logging_from_conf(conf, project, version):
|
|
log_root = getLogger(None).logger
|
|
|
|
# Remove all handlers
|
|
for handler in list(log_root.handlers):
|
|
log_root.removeHandler(handler)
|
|
|
|
logpath = _get_log_file_path(conf)
|
|
if logpath:
|
|
if conf.watch_log_file and platform.system() == 'Linux':
|
|
from oslo_log import watchers
|
|
file_handler = watchers.FastWatchedFileHandler
|
|
else:
|
|
file_handler = logging.handlers.WatchedFileHandler
|
|
|
|
filelog = file_handler(logpath)
|
|
log_root.addHandler(filelog)
|
|
|
|
if conf.use_stderr:
|
|
streamlog = handlers.ColorHandler()
|
|
log_root.addHandler(streamlog)
|
|
|
|
if conf.use_journal:
|
|
journal = handlers.OSJournalHandler()
|
|
log_root.addHandler(journal)
|
|
|
|
# if None of the above are True, then fall back to standard out
|
|
if not logpath and not conf.use_stderr and not conf.use_journal:
|
|
# pass sys.stdout as a positional argument
|
|
# python2.6 calls the argument strm, in 2.7 it's stream
|
|
streamlog = handlers.ColorHandler(sys.stdout)
|
|
log_root.addHandler(streamlog)
|
|
|
|
if conf.publish_errors:
|
|
handler = importutils.import_object(
|
|
"oslo_messaging.notify.log_handler.PublishErrorsHandler",
|
|
logging.ERROR)
|
|
log_root.addHandler(handler)
|
|
|
|
if conf.use_syslog:
|
|
global syslog
|
|
if syslog is None:
|
|
raise RuntimeError("syslog is not available on this platform")
|
|
facility = _find_facility(conf.syslog_log_facility)
|
|
syslog_handler = handlers.OSSysLogHandler(facility=facility)
|
|
log_root.addHandler(syslog_handler)
|
|
|
|
datefmt = conf.log_date_format
|
|
for handler in log_root.handlers:
|
|
handler.setFormatter(formatters.ContextFormatter(project=project,
|
|
version=version,
|
|
datefmt=datefmt,
|
|
config=conf))
|
|
_refresh_root_level(conf.debug)
|
|
|
|
for pair in conf.default_log_levels:
|
|
mod, _sep, level_name = pair.partition('=')
|
|
logger = logging.getLogger(mod)
|
|
numeric_level = None
|
|
try:
|
|
# NOTE(harlowja): integer's are valid level names, and for some
|
|
# libraries they have a lower level than DEBUG that is typically
|
|
# defined at level 5, so to make that accessible, try to convert
|
|
# this to a integer, and if not keep the original...
|
|
numeric_level = int(level_name)
|
|
except ValueError: # nosec
|
|
pass
|
|
if numeric_level is not None:
|
|
logger.setLevel(numeric_level)
|
|
else:
|
|
logger.setLevel(level_name)
|
|
|
|
if conf.rate_limit_burst >= 1 and conf.rate_limit_interval >= 1:
|
|
from oslo_log import rate_limit
|
|
rate_limit.install_filter(conf.rate_limit_burst,
|
|
conf.rate_limit_interval,
|
|
conf.rate_limit_except)
|
|
|
|
_loggers = {}
|
|
|
|
|
|
def get_loggers():
|
|
"""Return a copy of the oslo loggers dictionary."""
|
|
return _loggers.copy()
|
|
|
|
|
|
def getLogger(name=None, project='unknown', version='unknown'):
|
|
"""Build a logger with the given name.
|
|
|
|
:param name: The name for the logger. This is usually the module
|
|
name, ``__name__``.
|
|
:type name: string
|
|
:param project: The name of the project, to be injected into log
|
|
messages. For example, ``'nova'``.
|
|
:type project: string
|
|
:param version: The version of the project, to be injected into log
|
|
messages. For example, ``'2014.2'``.
|
|
:type version: string
|
|
"""
|
|
# NOTE(dhellmann): To maintain backwards compatibility with the
|
|
# old oslo namespace package logger configurations, and to make it
|
|
# possible to control all oslo logging with one logger node, we
|
|
# replace "oslo_" with "oslo." so that modules under the new
|
|
# non-namespaced packages get loggers as though they are.
|
|
if name and name.startswith('oslo_'):
|
|
name = 'oslo.' + name[5:]
|
|
if name not in _loggers:
|
|
_loggers[name] = KeywordArgumentAdapter(logging.getLogger(name),
|
|
{'project': project,
|
|
'version': version})
|
|
return _loggers[name]
|
|
|
|
|
|
def get_default_log_levels():
|
|
"""Return the Oslo Logging default log levels.
|
|
|
|
Returns a copy of the list so an application can change the value
|
|
and not affect the default value used in the log_opts configuration
|
|
setup.
|
|
"""
|
|
return list(_options.DEFAULT_LOG_LEVELS)
|
|
|
|
|
|
def is_debug_enabled(conf):
|
|
"""Determine if debug logging mode is enabled."""
|
|
return conf.debug
|