diff options
-rw-r--r-- | src/software/lmi/software/util/cmpi_logging.py | 282 |
1 files changed, 282 insertions, 0 deletions
diff --git a/src/software/lmi/software/util/cmpi_logging.py b/src/software/lmi/software/util/cmpi_logging.py new file mode 100644 index 0000000..b3a76c4 --- /dev/null +++ b/src/software/lmi/software/util/cmpi_logging.py @@ -0,0 +1,282 @@ +# Software Management Providers +# +# Copyright (C) 2012-2013 Red Hat, Inc. All rights reserved. +# +# This library is free software; you can redistribute it and/or +# modify it under the terms of the GNU Lesser General Public +# License as published by the Free Software Foundation; either +# version 2.1 of the License, or (at your option) any later version. +# +# This library is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU +# Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public +# License along with this library; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA +# +# Authors: Michal Minar <miminar@redhat.com> +# +""" +Module devoted to logging facilities. +""" + +import inspect +from itertools import chain +import logging +import logging.config +import os + +from lmi.common import cmpi_logging + +DEFAULT_LOGGING_CONFIG = { + "version" : 1, + 'disable_existing_loggers' : True, + "formatters": { + # this is a message format for logging function/method calls + # it's manually set up in YumWorker's init method + "default": { + "()": "lmi.software.util.cmpi_logging.DispatchingFormatter", + "formatters" : { + "lmi.software.util.cmpi_logging.trace_function_or_method": + "%(levelname)s:%(message)s" + }, + "default" : "%(levelname)s:%(module)s:" + "%(funcName)s:%(lineno)d - %(message)s" + }, + }, + "handlers": { + "stderr" : { + "class" : "logging.StreamHandler", + "level" : "ERROR", + "formatter": "default", + }, + "cmpi" : { + "()" : "lmi.common.cmpi_logging.CMPILogHandler", + # this must be filled with broker env logger + "cmpi_logger" : None, + "level" : "ERROR", + "formatter" : "default" + }, + }, + "root": { + "level": "ERROR", + "handlers" : ["cmpi"], + }, + } + +LOGGING_LEVELS = { + "critical" : logging.CRITICAL, + "error" : logging.ERROR, + "warning" : logging.WARNING, + "warn" : logging.WARNING, + "info" : logging.INFO, + "trace_warning" : cmpi_logging.TRACE_WARNING, + "trace_info" : cmpi_logging.TRACE_INFO, + "trace_verbose" : cmpi_logging.TRACE_VERBOSE, + "debug" : logging.DEBUG +} + +class DispatchingFormatter: + """ + Formatter class for logging module. It allows to predefine different + format string for paricular module names. + + There is no way, how to setup this formatter in configuration file. + """ + def __init__(self, formatters, default): + """ + *format* in parameters description can be either ``string`` or + another formatter object. + + :param formatters (``dict``) Mapping of module names to *format*. + :param default Default *format*. + """ + for k, formatter in formatters.items(): + if isinstance(formatter, basestring): + formatters[k] = logging.Formatter(formatter) + self._formatters = formatters + if isinstance(default, basestring): + default = logging.Formatter(default) + self._default_formatter = default + + def format(self, record): + """ + Interface for logging module. + """ + formatter = self._formatters.get(record.name, self._default_formatter) + return formatter.format(record) + +# ***************************************************************************** +# Decorators +# ***************************************************************************** +def trace_function_or_method(is_method=False, frame_level=1): + """ + Factory for function and method decorators. Generated decorators + log every calls and exits of decorated functions or methods. + + Logged information contain the caller's module and line together with + called function's module, function name and line number. + + :param is_method: (``bool``) Whether returned decorator is targeted + for use upon a method of a class. It modified logged function by + prepending owning class name. + :param frame_level: (``int``) Number of nested frames to skip when + searching for called function scope by inspecting stack upwards. + When the result of this function is applied directly on the definition + of function, it's value should be 1. When used from inside of some + other factory, it must be increased by 1. + """ + + assert frame_level >= 1 + + def _decorator(func): + """ + Decorator for logging entries and exits of function or method. + """ + if not inspect.ismethod(func) and not inspect.isfunction(func): + raise TypeError("func must be a function") + + def _print_value(val): + """ + Used here for printing function arguments. Shortens the output + string, if that would be too long. + """ + if isinstance(val, list): + if len(val) < 2: + return str(val) + else: + return "[%s, ...]" % _print_value(val[0]) + return str(val) + + logger = logging.getLogger(__name__+'.trace_function_or_method') + module = func.__module__.split('.')[-1] + frm = inspect.currentframe() + for i in range(frame_level): + frm = frm.f_back + lineno = frm.f_lineno + del frm + classname = inspect.getouterframes( + inspect.currentframe())[frame_level][3] + + def _wrapper(self, *args, **kwargs): + """ + Wrapper for function or method, that does the logging. + """ + if logger.isEnabledFor(logging.DEBUG): + frm = inspect.currentframe() + logargs = { + "caller_file" : os.path.basename(os.path.splitext( + frm.f_back.f_code.co_filename)[0]), + "caller_lineno" : frm.f_back.f_lineno, + "module" : module, + "func" : classname + "." + func.__name__ + if is_method else func.__name__, + "lineno" : lineno, + "action" : "entering", + "args" : ", ".join(chain( + (_print_value(a) for a in args), + ( "%s=%s"%(k, _print_value(v)) + for k, v in kwargs.items()))) + } + + if not logargs["args"]: + logargs["args"] = "" + else: + logargs["args"] = " with args=(%s)" % logargs["args"] + logger.debug("%(caller_file)s:%(caller_lineno)d - %(action)s" + " %(module)s:%(func)s:%(lineno)d%(args)s" , logargs) + try: + result = func(self, *args, **kwargs) + if logger.isEnabledFor(logging.DEBUG): + logargs["action"] = "exiting" + logger.debug("%(caller_file)s:%(caller_lineno)d" + " - %(action)s %(module)s:%(func)s:%(lineno)d", + logargs) + except Exception as exc: + if logger.isEnabledFor(logging.DEBUG): + logargs['action'] = 'exiting' + logargs['error'] = str(exc) + logger.debug("%(caller_file)s:%(caller_lineno)d" + " - %(action)s %(module)s:%(func)s:%(lineno)d" + " with error: %(error)s", logargs) + raise + return result + + return _wrapper + + return _decorator + +def trace_function(func, frame_level=1): + """ Convenience function used for decorating simple functions. """ + return trace_function_or_method(frame_level=frame_level + 1)(func) + +def trace_method(func, frame_level=1): + """ Convenience function used for decorating methods. """ + return trace_function_or_method(True, frame_level + 1)(func) + +def setup(env, config): + """ + Set up the logging with options given by SoftwareConfiguration instance. + This should be called at process's startup before any message is sent to + log. + + :param env: (``ProviderEnvironment``) Provider environment, taken + from CIMOM callback (e.g. ``get_providers()``). + :param config: (``BaseConfiguration``) Configuration with Log section + containing settings for logging. + """ + cp = config.config + logging_setup = False + try: + path = config.file_path('Log', 'FileConfig') + if not os.path.exists(path): + logging.getLogger(__name__).error('given FileConfig "%s" does' + ' not exist', path) + else: + logging.config.fileConfig(path) + logging_setup = True + except Exception: + if cp.has_option('Log', 'FileConfig'): + logging.getLogger(__name__).exception( + 'failed to setup logging from FileConfig') + if logging_setup is False: + defaults = DEFAULT_LOGGING_CONFIG.copy() + defaults["handlers"]["cmpi"]["cmpi_logger"] = env.get_logger() + if config.stderr: + defaults["root"]["handlers"] = ["stderr"] + level = config.logging_level + if not level in LOGGING_LEVELS: + logging.getLogger(__name__).error( + 'level name "%s" not supported', level) + else: + level = LOGGING_LEVELS[level] + for handler in defaults["handlers"].values(): + handler["level"] = level + defaults["root"]["level"] = level + logging.config.dictConfig(defaults) + # needed for shared code under lmi.common + cmpi_logging.logger = logging.getLogger('lmi.common') + +def get_logger(module_name): + """ + Convenience function for getting callable returning logger for particular + module name. It's supposed to be used at module's level to assign its + result to global variable like this: + + LOG = cmpi_logging.get_logger(__name__) + + This can be used in module's functions and classes like this: + + def module_function(param): + LOG().debug("this is debug statement logging param: %s", param) + + Thanks to ``LOG`` being a callable, it always returns valid logger object + with current configuration, which may change overtime. + """ + def _logger(): + """ Callable used to obtain current logger object. """ + return logging.getLogger(module_name) + return _logger + |