Mercurial > libervia-backend
changeset 1021:a836b6da2c5c
core (log): moved configuration to core.log_config; this avoid import issues with pyjamas.
| author | Goffi <goffi@goffi.org> |
|---|---|
| date | Wed, 14 May 2014 12:51:24 +0200 |
| parents | adbde4a3a52f |
| children | 002ee8397208 |
| files | frontends/src/primitivus/primitivus frontends/src/wix/wix src/core/log.py src/core/log_config.py src/sat.tac |
| diffstat | 5 files changed, 534 insertions(+), 502 deletions(-) [+] |
line wrap: on
line diff
--- a/frontends/src/primitivus/primitivus Tue May 13 17:17:57 2014 +0200 +++ b/frontends/src/primitivus/primitivus Wed May 14 12:51:24 2014 +0200 @@ -20,8 +20,9 @@ from sat.core.i18n import _ from sat_frontends.primitivus.constants import Const as C +from sat.core import log_config +log_config.satConfigure(C.LOG_BACKEND_STANDARD, C) from sat.core import log as logging -logging.satConfigure(C.LOG_BACKEND_STANDARD, C) log = logging.getLogger(__name__) import urwid from urwid_satext import sat_widgets
--- a/frontends/src/wix/wix Tue May 13 17:17:57 2014 +0200 +++ b/frontends/src/wix/wix Wed May 14 12:51:24 2014 +0200 @@ -19,8 +19,8 @@ from sat_frontends.wix.constants import Const as C -from sat.core import log -log.satConfigure(C.LOG_BACKEND_STANDARD, C) +from sat.core import log_config +log_config.satConfigure(C.LOG_BACKEND_STANDARD, C) import wx from sat_frontends.wix.main_window import MainWindow
--- a/src/core/log.py Tue May 13 17:17:57 2014 +0200 +++ b/src/core/log.py Wed May 14 12:51:24 2014 +0200 @@ -23,9 +23,9 @@ from sat.core.constants import Const as C from sat.core import exceptions -_backend = None +backend = None _loggers = {} -_handlers = {} +handlers = {} class Filtered(Exception): @@ -101,12 +101,11 @@ except KeyError as e: if e.args[0] == 'profile': # XXX: %(profile)s use some magic with introspection, for debugging purpose only *DO NOT* use in production - record['profile'] = _getProfile() + record['profile'] = configure_cls[backend].getProfile() return self.fmt % record else: raise e - def debug(self, msg): self.log(C.LOG_LVL_DEBUG, msg) @@ -123,23 +122,6 @@ self.log(C.LOG_LVL_CRITICAL, msg) -class TwistedLogger(Logger): - colors = True - force_colors = False - - def __init__(self, *args, **kwargs): - super(TwistedLogger, self).__init__(*args, **kwargs) - from twisted.python import log - self.twisted_log = log - - def out(self, message, level=None): - """Actually log the message - - @param message: formatted message - """ - self.twisted_log.msg(message.encode('utf-8', 'ignore'), sat_logged=True, level=level) - - class FilterName(object): """Filter on logger name according to a regex""" @@ -169,83 +151,13 @@ log_record.name = dict_record['name'] return self.filter(log_record) == 1 -def memoryGet(size=None): - """Return buffered logs - @param size: number of logs to return - """ - if not C.LOG_OPT_OUTPUT_MEMORY in _handlers: - raise ValueError('memory output is not used') - if _backend == C.LOG_BACKEND_STANDARD: - mem_handler = _handlers[C.LOG_OPT_OUTPUT_MEMORY] - return (log_msg for log_msg in mem_handler.buffer[size if size is None else -size:]) - else: - raise NotImplementedError - -def _getProfile(): - """Try to find profile value using introspection""" - import inspect - stack = inspect.stack() - current_path = stack[0][1] - for frame_data in stack[:-1]: - if frame_data[1] != current_path: - if _backend == C.LOG_BACKEND_STANDARD and "/logging/__init__.py" in frame_data[1]: - continue - break - - frame = frame_data[0] - args = inspect.getargvalues(frame) - try: - profile = args.locals.get('profile') or args.locals['profile_key'] - except (TypeError, KeyError): - try: - try: - profile = args.locals['self'].profile - except AttributeError: - try: - profile = args.locals['self'].parent.profile - except AttributeError: - profile = args.locals['self'].host.profile # used in quick_frontend for single profile configuration - except Exception: - # we can't find profile, we return an empty value - profile = '' - return profile - -def _ansiColors(level, message): - """Colorise message depending on level for terminals - - @param level: one of C.LOG_LEVELS - @param message: formatted message to log - @return: message with ANSI escape codes for coloration - """ - if level == C.LOG_LVL_DEBUG: - out = (C.ANSI_FG_CYAN, message, C.ANSI_RESET) - elif level == C.LOG_LVL_WARNING: - out = (C.ANSI_FG_YELLOW, message, C.ANSI_RESET) - elif level == C.LOG_LVL_ERROR: - out = (C.ANSI_FG_RED, - C.ANSI_BLINK, - r'/!\ ', - C.ANSI_BLINK_OFF, - message, - C.ANSI_RESET) - elif level == C.LOG_LVL_CRITICAL: - out = (C.ANSI_BOLD, - C.ANSI_FG_RED, - 'Guru Meditation ', - C.ANSI_NORMAL_WEIGHT, - message, - C.ANSI_RESET) - else: - out = message - return ''.join(out) - - -class Configure(object): +class ConfigureBase(object): LOGGER_CLASS = Logger def __init__(self, level=None, fmt=None, output=None, logger=None, colors=False, force_colors=False): - """Configure backend + """Configure a backend + @param level: one of C.LOG_LEVELS @param fmt: format string, pretty much as in std logging. Accept the following keywords (maybe more depending on backend): - "message" @@ -276,72 +188,6 @@ pass def configureLevel(self, level): - pass - - def configureFormat(self, fmt): - pass - - def configureOutput(self, output): - pass - - def configureLogger(self, logger): - pass - - def configureColors(self, colors, force_colors): - pass - - def postTreatment(self): - pass - - def manageOutputs(self, outputs_raw): - """ Parse output option in a backend agnostic way, and fill _handlers consequently - - @param outputs_raw: output option as enterred in environment variable or in configuration - """ - if not outputs_raw: - return - outputs = outputs_raw.split(C.LOG_OPT_OUTPUT_SEP) - global _handlers - if len(outputs) == 1: - _handlers[C.LOG_OPT_OUTPUT_FILE] = [outputs.pop()] - - for output in outputs: - if not output: - continue - if output[-1] == ')': - # we have options - opt_begin = output.rfind('(') - options = output[opt_begin+1:-1] - output = output[:opt_begin] - else: - options = None - - if output not in (C.LOG_OPT_OUTPUT_DEFAULT, C.LOG_OPT_OUTPUT_FILE, C.LOG_OPT_OUTPUT_MEMORY): - raise ValueError(u"Invalid output [%s]" % output) - - if output == C.LOG_OPT_OUTPUT_DEFAULT: - # no option for defaut handler - _handlers[output] = None - elif output == C.LOG_OPT_OUTPUT_FILE: - if not options: - ValueError("%(handler)s output need a path as option" % {'handler': output}) - _handlers.setdefault(output, []).append(options) - options = None # option are parsed, we can empty them - elif output == C.LOG_OPT_OUTPUT_MEMORY: - # we have memory handler, option can be the len limit or None - try: - limit = int(options) - options = None # option are parsed, we can empty them - except (TypeError, ValueError): - limit = C.LOG_OPT_OUTPUT_MEMORY_LIMIT - _handlers[output] = limit - - if options: # we should not have unparsed options - raise ValueError(u"options [%(options)s] are not supported for %(handler)s output" % {'options': options, 'handler': output}) - - -class ConfigureBasic(Configure): - def configureLevel(self, level): if level is not None: # we deactivate methods below level level_idx = C.LOG_LEVELS.index(level) @@ -366,363 +212,144 @@ Logger.filter_name = FilterName(logger) def configureColors(self, colors, force_colors): - if colors: - import sys - if force_colors or sys.stdout.isatty(): # FIXME: isatty should be tested on each handler, not globaly - # we need colors - Logger.post_treat = lambda self, level, message: _ansiColors(level, message) - elif force_colors: - raise ValueError("force_colors can't be used if colors is False") + pass + + def postTreatment(self): + pass + + def manageOutputs(self, outputs_raw): + """ Parse output option in a backend agnostic way, and fill handlers consequently + + @param outputs_raw: output option as enterred in environment variable or in configuration + """ + if not outputs_raw: + return + outputs = outputs_raw.split(C.LOG_OPT_OUTPUT_SEP) + global handlers + if len(outputs) == 1: + handlers[C.LOG_OPT_OUTPUT_FILE] = [outputs.pop()] + + for output in outputs: + if not output: + continue + if output[-1] == ')': + # we have options + opt_begin = output.rfind('(') + options = output[opt_begin+1:-1] + output = output[:opt_begin] + else: + options = None + + if output not in (C.LOG_OPT_OUTPUT_DEFAULT, C.LOG_OPT_OUTPUT_FILE, C.LOG_OPT_OUTPUT_MEMORY): + raise ValueError(u"Invalid output [%s]" % output) + + if output == C.LOG_OPT_OUTPUT_DEFAULT: + # no option for defaut handler + handlers[output] = None + elif output == C.LOG_OPT_OUTPUT_FILE: + if not options: + ValueError("%(handler)s output need a path as option" % {'handler': output}) + handlers.setdefault(output, []).append(options) + options = None # option are parsed, we can empty them + elif output == C.LOG_OPT_OUTPUT_MEMORY: + # we have memory handler, option can be the len limit or None + try: + limit = int(options) + options = None # option are parsed, we can empty them + except (TypeError, ValueError): + limit = C.LOG_OPT_OUTPUT_MEMORY_LIMIT + handlers[output] = limit + + if options: # we should not have unparsed options + raise ValueError(u"options [%(options)s] are not supported for %(handler)s output" % {'options': options, 'handler': output}) + + @staticmethod + def memoryGet(size=None): + """Return buffered logs + + @param size: number of logs to return + """ + raise NotImplementedError + + @staticmethod + def ansiColors(level, message): + """Colorise message depending on level for terminals + + @param level: one of C.LOG_LEVELS + @param message: formatted message to log + @return: message with ANSI escape codes for coloration + """ + if level == C.LOG_LVL_DEBUG: + out = (C.ANSI_FG_CYAN, message, C.ANSI_RESET) + elif level == C.LOG_LVL_WARNING: + out = (C.ANSI_FG_YELLOW, message, C.ANSI_RESET) + elif level == C.LOG_LVL_ERROR: + out = (C.ANSI_FG_RED, + C.ANSI_BLINK, + r'/!\ ', + C.ANSI_BLINK_OFF, + message, + C.ANSI_RESET) + elif level == C.LOG_LVL_CRITICAL: + out = (C.ANSI_BOLD, + C.ANSI_FG_RED, + 'Guru Meditation ', + C.ANSI_NORMAL_WEIGHT, + message, + C.ANSI_RESET) + else: + out = message + return ''.join(out) + + @staticmethod + def getProfile(): + """Try to find profile value using introspection""" + raise NotImplementedError -class ConfigureTwisted(ConfigureBasic): - LOGGER_CLASS = TwistedLogger - - def changeObserver(self, observer, can_colors=False): - """Install a hook on observer to manage SàT specificities - - @param observer: original observer to hook - @param can_colors: True if observer can display ansi colors - """ - def observer_hook(event): - """redirect non SàT log to twisted_logger, and add colors when possible""" - if 'sat_logged' in event: # we only want our own logs, other are managed by twistedObserver - # we add colors if possible - if (can_colors and self.LOGGER_CLASS.colors) or self.LOGGER_CLASS.force_colors: - message = event.get('message', tuple()) - level = event.get('level', C.LOG_LVL_INFO) - if message: - event['message'] = (_ansiColors(level, ''.join(message)),) # must be a tuple - observer(event) # we can now call the original observer - - return observer_hook - - def changeFileLogObserver(self, observer): - """Install SàT hook for FileLogObserver - - if the output is a tty, we allow colors, else we don't - @param observer: original observer to hook - """ - log_obs = observer.__self__ - log_file = log_obs.write.__self__ - try: - can_colors = log_file.isatty() - except AttributeError: - can_colors = False - return self.changeObserver(observer, can_colors=can_colors) - - def installObserverHook(self, observer): - """Check observer type and install SàT hook when possible - - @param observer: observer to hook - @return: hooked observer or original one - """ - if hasattr(observer, '__self__'): - ori = observer - if isinstance(observer.__self__, self.log.FileLogObserver): - observer = self.changeFileLogObserver(observer) - elif isinstance(observer.__self__, self.log.DefaultObserver): - observer = self.changeObserver(observer, can_colors=True) - else: - # we use print because log system is not fully initialized - print("Unmanaged observer [%s]" % observer) - return observer - self.observers[ori] = observer - return observer - - def preTreatment(self): - """initialise needed attributes, and install observers hooks""" - self.observers = {} - from twisted.python import log - self.log = log - self.log_publisher = log.msg.__self__ - def addObserverObserver(self_logpub, other): - """Install hook so we know when a new observer is added""" - other = self.installObserverHook(other) - return self_logpub._originalAddObserver(other) - def removeObserverObserver(self_logpub, ori): - """removeObserver hook fix - - As we wrap the original observer, the original removeObserver may want to remove the original object instead of the wrapper, this method fix this - """ - if ori in self.observers: - self_logpub._originalRemoveObserver(self.observers[ori]) - else: - try: - self_logpub._originalRemoveObserver(ori) - except ValueError: - try: - ori in self.cleared_observers - except AttributeError: - raise ValueError("Unknown observer") - - # we replace addObserver/removeObserver by our own - log.LogPublisher._originalAddObserver = log.LogPublisher.addObserver - log.LogPublisher._originalRemoveObserver = log.LogPublisher.removeObserver - import types # see https://stackoverflow.com/a/4267590 (thx Chris Morgan/aaronasterling) - log.addObserver = types.MethodType(addObserverObserver, self.log_publisher, log.LogPublisher) - log.removeObserver = types.MethodType(removeObserverObserver, self.log_publisher, log.LogPublisher) - - # we now change existing observers - for idx, observer in enumerate(self.log_publisher.observers): - self.log_publisher.observers[idx] = self.installObserverHook(observer) - - - def configureLevel(self, level): - self.LOGGER_CLASS.level = level - super(ConfigureTwisted, self).configureLevel(level) - - def configureOutput(self, output): - import sys - if output is None: - output = C.LOG_OPT_OUTPUT_SEP + C.LOG_OPT_OUTPUT_DEFAULT - self.manageOutputs(output) - addObserver = self.log.addObserver - - if C.LOG_OPT_OUTPUT_DEFAULT in _handlers: - # default output is already managed, we just add output to stdout if we are in debug mode - from twisted.internet import defer - if defer.Deferred.debug: - addObserver(self.log.FileLogObserver(sys.stdout).emit) - else: - # \\default is not in the output, so we remove current observers - self.cleared_observers = self.log_publisher.observers - self.observers.clear() - del self.log_publisher.observers[:] - # and we forbid twistd to add any observer - self.log.addObserver = lambda other: None - - if C.LOG_OPT_OUTPUT_FILE in _handlers: - from twisted.python import logfile - for path in _handlers[C.LOG_OPT_OUTPUT_FILE]: - log_file = sys.stdout if path == '-' else logfile.LogFile.fromFullPath(path) - addObserver(self.log.FileLogObserver(log_file).emit) - - if C.LOG_OPT_OUTPUT_MEMORY in _handlers: - raise NotImplementedError("Memory observer is not implemented in Twisted backend") - - def configureColors(self, colors, force_colors): - self.LOGGER_CLASS.colors = colors - self.LOGGER_CLASS.force_colors = force_colors - if force_colors and not colors: - raise ValueError('colors must be True if force_colors is True') - - def postTreatment(self): - """Install twistedObserver which manage non SàT logs""" - def twistedObserver(event): - """Observer which redirect log message not produced by SàT to SàT logging system""" - if not 'sat_logged' in event: - # this log was not produced by SàT - from twisted.python import log - text = log.textFromEventDict(event) - if text is None: - return - twisted_logger = getLogger(C.LOG_TWISTED_LOGGER) - log_method = twisted_logger.error if event.get('isError', False) else twisted_logger.info - log_method(text.decode('utf-8')) - - self.log_publisher._originalAddObserver(twistedObserver) - - -class ConfigureCustom(ConfigureBasic): +class ConfigureCustom(ConfigureBase): LOGGER_CLASS = None def __init__(self, logger_class, *args, **kwargs): ConfigureCustom.LOGGER_CLASS = logger_class -class ConfigureStandard(Configure): - - def __init__(self, level=None, fmt=None, output=None, logger=None, colors=False, force_colors=False): - if fmt is None: - fmt = C.LOG_OPT_FORMAT[1] - if output is None: - output = C.LOG_OPT_OUTPUT[1] - super(ConfigureStandard, self).__init__(level, fmt, output, logger, colors, force_colors) - - def preTreatment(self): - """We use logging methods directly, instead of using Logger""" - global getLogger - global debug - global info - global warning - global error - global critical - import logging - getLogger = logging.getLogger - debug = logging.debug - info = logging.info - warning = logging.warning - error = logging.error - critical = logging.critical - - def configureLevel(self, level): - if level is None: - level = C.LOG_LVL_DEBUG - self.level = level - - def configureFormat(self, fmt): - import logging - - class SatFormatter(logging.Formatter): - u"""Formatter which manage SàT specificities""" - _format = fmt - _with_profile = '%(profile)s' in fmt - - def __init__(self, can_colors=False): - super(SatFormatter, self).__init__(self._format) - self.can_colors = can_colors - - def format(self, record): - if self._with_profile: - record.profile = _getProfile() - s = super(SatFormatter, self).format(record) - if self.with_colors and (self.can_colors or self.force_colors): - s = _ansiColors(record.levelname, s) - return s - - self.formatterClass = SatFormatter - - def configureOutput(self, output): - self.manageOutputs(output) - - def configureLogger(self, logger): - self.name_filter = FilterName(logger) if logger else None - - def configureColors(self, colors, force_colors): - self.formatterClass.with_colors = colors - self.formatterClass.force_colors = force_colors - if not colors and force_colors: - raise ValueError("force_colors can't be used if colors is False") - - def _addHandler(self, root_logger, hdlr, can_colors=False): - hdlr.setFormatter(self.formatterClass(can_colors)) - root_logger.addHandler(hdlr) - root_logger.setLevel(self.level) - if self.name_filter is not None: - hdlr.addFilter(self.name_filter) - - def postTreatment(self): - import logging - root_logger = logging.getLogger() - if len(root_logger.handlers) == 0: - for handler, options in _handlers.items(): - if handler == C.LOG_OPT_OUTPUT_DEFAULT: - hdlr = logging.StreamHandler() - try: - can_colors = hdlr.stream.isatty() - except AttributeError: - can_colors = False - self._addHandler(root_logger, hdlr, can_colors=can_colors) - elif handler == C.LOG_OPT_OUTPUT_MEMORY: - from logging.handlers import BufferingHandler - class SatMemoryHandler(BufferingHandler): - def emit(self, record): - super(SatMemoryHandler, self).emit(self.format(record)) - hdlr = SatMemoryHandler(options) - _handlers[handler] = hdlr # we keep a reference to the handler to read the buffer later - self._addHandler(root_logger, hdlr, can_colors=False) - elif handler == C.LOG_OPT_OUTPUT_FILE: - import os.path - for path in options: - hdlr = logging.FileHandler(os.path.expanduser(path)) - self._addHandler(root_logger, hdlr, can_colors=False) - else: - raise ValueError("Unknown handler type") - else: - root_logger.warning(u"Handlers already set on root logger") +configure_cls = { None: ConfigureBase, + C.LOG_BACKEND_CUSTOM: ConfigureCustom + } # XXX: (key: backend, value: Configure subclass) must be filled when new backend are added -def configure(backend=C.LOG_BACKEND_STANDARD, **options): +def configure(backend_, **options): """Configure logging behaviour @param backend: can be: - C.LOG_BACKEND_STANDARD: use standard logging module - C.LOG_BACKEND_TWISTED: use twisted logging module (with standard logging observer) C.LOG_BACKEND_BASIC: use a basic print based logging C.LOG_BACKEND_CUSTOM: use a given Logger subclass """ - global _backend - if _backend is not None: + global backend + if backend is not None: raise exceptions.InternalError("Logging can only be configured once") - _backend = backend - - if backend == C.LOG_BACKEND_BASIC: - ConfigureBasic(**options) - - elif backend == C.LOG_BACKEND_TWISTED: - ConfigureTwisted(**options) - - elif backend == C.LOG_BACKEND_STANDARD: - ConfigureStandard(**options) - - elif backend == C.LOG_BACKEND_CUSTOM: - logger_class = options.pop('logger_class') - ConfigureCustom(logger_class, **options) - - else: - raise ValueError("unknown backend") - -def _parseOptions(options): - """Parse string options as given in conf or environment variable, and return expected python value - - @param options (dict): options with (key: name, value: string value) - """ - COLORS = C.LOG_OPT_COLORS[0] - LEVEL = C.LOG_OPT_LEVEL[0] + backend = backend_ - if COLORS in options: - if options[COLORS].lower() in ('1', 'true'): - options[COLORS] = True - elif options[COLORS] == 'force': - options[COLORS] = True - options['force_colors'] = True - else: - options[COLORS] = False - if LEVEL in options: - level = options[LEVEL].upper() - if level not in C.LOG_LEVELS: - level = C.LOG_LVL_INFO - options[LEVEL] = level - -def satConfigure(backend=C.LOG_BACKEND_STANDARD, const=None): - """Configure logging system for SàT, can be used by frontends + try: + configure_class = configure_cls[backend] + except KeyError: + raise ValueError("unknown backend [%s]" % backend) + if backend == C.LOG_BACKEND_CUSTOM: + logger_class = options.pop('logger_class') + configure_class(logger_class, **options) + else: + configure_class(**options) - logs conf is read in SàT conf, then in environment variables. It must be done before Memory init - @param backend: backend to use, it can be: - - C.LOG_BACKEND_BASIC: print based backend - - C.LOG_BACKEND_TWISTED: Twisted logging backend - - C.LOG_BACKEND_STANDARD: standard logging backend - @param const: Const class to use instead of sat.core.constants.Const (mainly used to change default values) - """ - if const is not None: - global C - C = const - import ConfigParser - import os - log_conf = {} - config = ConfigParser.SafeConfigParser() - config.read(C.CONFIG_FILES) - for opt_name, opt_default in C.LOG_OPTIONS(): - try: - log_conf[opt_name] = os.environ[''.join((C.ENV_PREFIX, C.LOG_OPT_PREFIX.upper(), opt_name.upper()))] - except KeyError: - try: - log_conf[opt_name] = config.get(C.LOG_OPT_SECTION, C.LOG_OPT_PREFIX + opt_name) - except (ConfigParser.NoOptionError, ConfigParser.NoSectionError): - log_conf[opt_name] = opt_default - - _parseOptions(log_conf) - configure(backend, **log_conf) +def memoryGet(size=None): + if not C.LOG_OPT_OUTPUT_MEMORY in handlers: + raise ValueError('memory output is not used') + return configure_cls[backend].memoryGet(size) def getLogger(name=C.LOG_BASE_LOGGER): - if _backend in (None, C.LOG_BACKEND_BASIC): - logger_class = ConfigureBasic.LOGGER_CLASS - elif _backend == C.LOG_BACKEND_TWISTED: - logger_class = ConfigureTwisted.LOGGER_CLASS - elif _backend == C.LOG_BACKEND_CUSTOM: - logger_class = ConfigureCustom.LOGGER_CLASS - else: - raise ValueError("This method should not be called with backend [%s]" % _backend) + try: + logger_class = configure_cls[backend].LOGGER_CLASS + except KeyError: + raise ValueError("This method should not be called with backend [%s]" % backend) return _loggers.setdefault(name, logger_class(name)) _root_logger = getLogger()
--- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/src/core/log_config.py Wed May 14 12:51:24 2014 +0200 @@ -0,0 +1,404 @@ +#!/usr/bin/python +# -*- coding: utf-8 -*- + +# SàT: a XMPP client +# Copyright (C) 2009, 2010, 2011, 2012, 2013, 2014 Jérôme Poisson (goffi@goffi.org) + +# This program is free software: you can redistribute it and/or modify +# it under the terms of the GNU Affero General Public License as published by +# the Free Software Foundation, either version 3 of the License, or +# (at your option) any later version. + +# This program 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 Affero General Public License for more details. + +# You should have received a copy of the GNU Affero General Public License +# along with this program. If not, see <http://www.gnu.org/licenses/>. + +"""High level logging functions""" +# XXX: this module use standard logging module when possible, but as SàT can work in different cases where logging is not the best choice (twisted, pyjamas, etc), it is necessary to have a dedicated module. Additional feature like environment variables and colors are also managed. + +from sat.core.constants import Const as C +from sat.core import log + + +class TwistedLogger(log.Logger): + colors = True + force_colors = False + + def __init__(self, *args, **kwargs): + super(TwistedLogger, self).__init__(*args, **kwargs) + from twisted.python import log as twisted_log + self.twisted_log = twisted_log + + def out(self, message, level=None): + """Actually log the message + + @param message: formatted message + """ + self.twisted_log.msg(message.encode('utf-8', 'ignore'), sat_logged=True, level=level) + + +class ConfigureBasic(log.ConfigureBase): + + def configureColors(self, colors, force_colors): + if colors: + import sys + if force_colors or sys.stdout.isatty(): # FIXME: isatty should be tested on each handler, not globaly + # we need colors + log.Logger.post_treat = lambda self, level, message: self.ansiColors(level, message) + elif force_colors: + raise ValueError("force_colors can't be used if colors is False") + + @staticmethod + def getProfile(): + """Try to find profile value using introspection""" + import inspect + stack = inspect.stack() + current_path = stack[0][1] + for frame_data in stack[:-1]: + if frame_data[1] != current_path: + if log.backend == C.LOG_BACKEND_STANDARD and "/logging/__init__.py" in frame_data[1]: + continue + break + + frame = frame_data[0] + args = inspect.getargvalues(frame) + try: + profile = args.locals.get('profile') or args.locals['profile_key'] + except (TypeError, KeyError): + try: + try: + profile = args.locals['self'].profile + except AttributeError: + try: + profile = args.locals['self'].parent.profile + except AttributeError: + profile = args.locals['self'].host.profile # used in quick_frontend for single profile configuration + except Exception: + # we can't find profile, we return an empty value + profile = '' + return profile + + +class ConfigureTwisted(ConfigureBasic): + LOGGER_CLASS = TwistedLogger + + def changeObserver(self, observer, can_colors=False): + """Install a hook on observer to manage SàT specificities + + @param observer: original observer to hook + @param can_colors: True if observer can display ansi colors + """ + def observer_hook(event): + """redirect non SàT log to twisted_logger, and add colors when possible""" + if 'sat_logged' in event: # we only want our own logs, other are managed by twistedObserver + # we add colors if possible + if (can_colors and self.LOGGER_CLASS.colors) or self.LOGGER_CLASS.force_colors: + message = event.get('message', tuple()) + level = event.get('level', C.LOG_LVL_INFO) + if message: + event['message'] = (self.ansiColors(level, ''.join(message)),) # must be a tuple + observer(event) # we can now call the original observer + + return observer_hook + + def changeFileLogObserver(self, observer): + """Install SàT hook for FileLogObserver + + if the output is a tty, we allow colors, else we don't + @param observer: original observer to hook + """ + log_obs = observer.__self__ + log_file = log_obs.write.__self__ + try: + can_colors = log_file.isatty() + except AttributeError: + can_colors = False + return self.changeObserver(observer, can_colors=can_colors) + + def installObserverHook(self, observer): + """Check observer type and install SàT hook when possible + + @param observer: observer to hook + @return: hooked observer or original one + """ + if hasattr(observer, '__self__'): + ori = observer + if isinstance(observer.__self__, self.twisted_log.FileLogObserver): + observer = self.changeFileLogObserver(observer) + elif isinstance(observer.__self__, self.twisted_log.DefaultObserver): + observer = self.changeObserver(observer, can_colors=True) + else: + # we use print because log system is not fully initialized + print("Unmanaged observer [%s]" % observer) + return observer + self.observers[ori] = observer + return observer + + def preTreatment(self): + """initialise needed attributes, and install observers hooks""" + self.observers = {} + from twisted.python import log as twisted_log + self.twisted_log = twisted_log + self.log_publisher = twisted_log.msg.__self__ + def addObserverObserver(self_logpub, other): + """Install hook so we know when a new observer is added""" + other = self.installObserverHook(other) + return self_logpub._originalAddObserver(other) + def removeObserverObserver(self_logpub, ori): + """removeObserver hook fix + + As we wrap the original observer, the original removeObserver may want to remove the original object instead of the wrapper, this method fix this + """ + if ori in self.observers: + self_logpub._originalRemoveObserver(self.observers[ori]) + else: + try: + self_logpub._originalRemoveObserver(ori) + except ValueError: + try: + ori in self.cleared_observers + except AttributeError: + raise ValueError("Unknown observer") + + # we replace addObserver/removeObserver by our own + twisted_log.LogPublisher._originalAddObserver = twisted_log.LogPublisher.addObserver + twisted_log.LogPublisher._originalRemoveObserver = twisted_log.LogPublisher.removeObserver + import types # see https://stackoverflow.com/a/4267590 (thx Chris Morgan/aaronasterling) + twisted_log.addObserver = types.MethodType(addObserverObserver, self.log_publisher, twisted_log.LogPublisher) + twisted_log.removeObserver = types.MethodType(removeObserverObserver, self.log_publisher, twisted_log.LogPublisher) + + # we now change existing observers + for idx, observer in enumerate(self.log_publisher.observers): + self.log_publisher.observers[idx] = self.installObserverHook(observer) + + def configureLevel(self, level): + self.LOGGER_CLASS.level = level + super(ConfigureTwisted, self).configureLevel(level) + + def configureOutput(self, output): + import sys + if output is None: + output = C.LOG_OPT_OUTPUT_SEP + C.LOG_OPT_OUTPUT_DEFAULT + self.manageOutputs(output) + addObserver = self.twisted_log.addObserver + + if C.LOG_OPT_OUTPUT_DEFAULT in log.handlers: + # default output is already managed, we just add output to stdout if we are in debug mode + from twisted.internet import defer + if defer.Deferred.debug: + addObserver(self.twisted_log.FileLogObserver(sys.stdout).emit) + else: + # \\default is not in the output, so we remove current observers + self.cleared_observers = self.log_publisher.observers + self.observers.clear() + del self.log_publisher.observers[:] + # and we forbid twistd to add any observer + self.twisted_log.addObserver = lambda other: None + + if C.LOG_OPT_OUTPUT_FILE in log.handlers: + from twisted.python import logfile + for path in log.handlers[C.LOG_OPT_OUTPUT_FILE]: + log_file = sys.stdout if path == '-' else logfile.LogFile.fromFullPath(path) + addObserver(self.twisted_log.FileLogObserver(log_file).emit) + + if C.LOG_OPT_OUTPUT_MEMORY in log.handlers: + raise NotImplementedError("Memory observer is not implemented in Twisted backend") + + def configureColors(self, colors, force_colors): + self.LOGGER_CLASS.colors = colors + self.LOGGER_CLASS.force_colors = force_colors + if force_colors and not colors: + raise ValueError('colors must be True if force_colors is True') + + def postTreatment(self): + """Install twistedObserver which manage non SàT logs""" + def twistedObserver(event): + """Observer which redirect log message not produced by SàT to SàT logging system""" + if not 'sat_logged' in event: + # this log was not produced by SàT + from twisted.python import log as twisted_log + text = twisted_log.textFromEventDict(event) + if text is None: + return + twisted_logger = log.getLogger(C.LOG_TWISTED_LOGGER) + log_method = twisted_logger.error if event.get('isError', False) else twisted_logger.info + log_method(text.decode('utf-8')) + + self.log_publisher._originalAddObserver(twistedObserver) + + +class ConfigureStandard(ConfigureBasic): + + def __init__(self, level=None, fmt=None, output=None, logger=None, colors=False, force_colors=False): + if fmt is None: + fmt = C.LOG_OPT_FORMAT[1] + if output is None: + output = C.LOG_OPT_OUTPUT[1] + super(ConfigureStandard, self).__init__(level, fmt, output, logger, colors, force_colors) + + def preTreatment(self): + """We use logging methods directly, instead of using Logger""" + import logging + log.getLogger = logging.getLogger + log.debug = logging.debug + log.info = logging.info + log.warning = logging.warning + log.error = logging.error + log.critical = logging.critical + + def configureLevel(self, level): + if level is None: + level = C.LOG_LVL_DEBUG + self.level = level + + def configureFormat(self, fmt): + import logging + + class SatFormatter(logging.Formatter): + u"""Formatter which manage SàT specificities""" + _format = fmt + _with_profile = '%(profile)s' in fmt + + def __init__(self, can_colors=False): + super(SatFormatter, self).__init__(self._format) + self.can_colors = can_colors + + def format(self, record): + if self._with_profile: + record.profile = ConfigureStandard.getProfile() + s = super(SatFormatter, self).format(record) + if self.with_colors and (self.can_colors or self.force_colors): + s = ConfigureStandard.ansiColors(record.levelname, s) + return s + + self.formatterClass = SatFormatter + + def configureOutput(self, output): + self.manageOutputs(output) + + def configureLogger(self, logger): + self.name_filter = log.FilterName(logger) if logger else None + + def configureColors(self, colors, force_colors): + self.formatterClass.with_colors = colors + self.formatterClass.force_colors = force_colors + if not colors and force_colors: + raise ValueError("force_colors can't be used if colors is False") + + def _addHandler(self, root_logger, hdlr, can_colors=False): + hdlr.setFormatter(self.formatterClass(can_colors)) + root_logger.addHandler(hdlr) + root_logger.setLevel(self.level) + if self.name_filter is not None: + hdlr.addFilter(self.name_filter) + + def postTreatment(self): + import logging + root_logger = logging.getLogger() + if len(root_logger.handlers) == 0: + for handler, options in log.handlers.items(): + if handler == C.LOG_OPT_OUTPUT_DEFAULT: + hdlr = logging.StreamHandler() + try: + can_colors = hdlr.stream.isatty() + except AttributeError: + can_colors = False + self._addHandler(root_logger, hdlr, can_colors=can_colors) + elif handler == C.LOG_OPT_OUTPUT_MEMORY: + from logging.handlers import BufferingHandler + class SatMemoryHandler(BufferingHandler): + def emit(self, record): + super(SatMemoryHandler, self).emit(self.format(record)) + hdlr = SatMemoryHandler(options) + log.handlers[handler] = hdlr # we keep a reference to the handler to read the buffer later + self._addHandler(root_logger, hdlr, can_colors=False) + elif handler == C.LOG_OPT_OUTPUT_FILE: + import os.path + for path in options: + hdlr = logging.FileHandler(os.path.expanduser(path)) + self._addHandler(root_logger, hdlr, can_colors=False) + else: + raise ValueError("Unknown handler type") + else: + root_logger.warning(u"Handlers already set on root logger") + + @staticmethod + def memoryGet(size=None): + """Return buffered logs + + @param size: number of logs to return + """ + mem_handler = log.handlers[C.LOG_OPT_OUTPUT_MEMORY] + return (log_msg for log_msg in mem_handler.buffer[size if size is None else -size:]) + + +log.configure_cls[C.LOG_BACKEND_BASIC] = ConfigureBasic +log.configure_cls[C.LOG_BACKEND_TWISTED] = ConfigureTwisted +log.configure_cls[C.LOG_BACKEND_STANDARD] = ConfigureStandard + +def configure(backend, **options): + """Configure logging behaviour + @param backend: can be: + C.LOG_BACKEND_STANDARD: use standard logging module + C.LOG_BACKEND_TWISTED: use twisted logging module (with standard logging observer) + C.LOG_BACKEND_BASIC: use a basic print based logging + C.LOG_BACKEND_CUSTOM: use a given Logger subclass + """ + return log.configure(backend, **options) + +def _parseOptions(options): + """Parse string options as given in conf or environment variable, and return expected python value + + @param options (dict): options with (key: name, value: string value) + """ + COLORS = C.LOG_OPT_COLORS[0] + LEVEL = C.LOG_OPT_LEVEL[0] + + if COLORS in options: + if options[COLORS].lower() in ('1', 'true'): + options[COLORS] = True + elif options[COLORS] == 'force': + options[COLORS] = True + options['force_colors'] = True + else: + options[COLORS] = False + if LEVEL in options: + level = options[LEVEL].upper() + if level not in C.LOG_LEVELS: + level = C.LOG_LVL_INFO + options[LEVEL] = level + +def satConfigure(backend=C.LOG_BACKEND_STANDARD, const=None): + """Configure logging system for SàT, can be used by frontends + + logs conf is read in SàT conf, then in environment variables. It must be done before Memory init + @param backend: backend to use, it can be: + - C.LOG_BACKEND_BASIC: print based backend + - C.LOG_BACKEND_TWISTED: Twisted logging backend + - C.LOG_BACKEND_STANDARD: standard logging backend + @param const: Const class to use instead of sat.core.constants.Const (mainly used to change default values) + """ + if const is not None: + global C + C = const + log.C = const + import ConfigParser + import os + log_conf = {} + config = ConfigParser.SafeConfigParser() + config.read(C.CONFIG_FILES) + for opt_name, opt_default in C.LOG_OPTIONS(): + try: + log_conf[opt_name] = os.environ[''.join((C.ENV_PREFIX, C.LOG_OPT_PREFIX.upper(), opt_name.upper()))] + except KeyError: + try: + log_conf[opt_name] = config.get(C.LOG_OPT_SECTION, C.LOG_OPT_PREFIX + opt_name) + except (ConfigParser.NoOptionError, ConfigParser.NoSectionError): + log_conf[opt_name] = opt_default + + _parseOptions(log_conf) + configure(backend, **log_conf)
--- a/src/sat.tac Tue May 13 17:17:57 2014 +0200 +++ b/src/sat.tac Wed May 14 12:51:24 2014 +0200 @@ -34,8 +34,8 @@ # XXX: We need to configure logs before any log method is used, so here is the best place. from sat.core.constants import Const as C -from sat.core import log -log.satConfigure(C.LOG_BACKEND_TWISTED) +from sat.core import log_config +log_config.satConfigure(C.LOG_BACKEND_TWISTED) # XXX: SAT must be imported after log configuration, because it write stuff to logs from sat.core.sat_main import SAT