--- a/src/core/log.py	Mon May 05 18:58:34 2014 +0200
+++ b/src/core/log.py	Mon May 05 18:58:34 2014 +0200
@@ -27,17 +27,36 @@
 _loggers = {}
 _handlers = {}
 
+
 class Filtered(Exception):
     pass
 
+
 class Logger(object):
     """High level logging class"""
-    fmt = None
-    filter_name = None
+    fmt = None # format option as given by user (e.g. SAT_LOG_LOGGER)
+    filter_name = None # filter to call
     post_treat = None
 
     def __init__(self, name):
-        self._name = name
+        if isinstance(name, Logger):
+            self.copy(name)
+        else:
+            self._name = name
+
+    def copy(self, other):
+        """Copy values from other Logger"""
+        self.fmt = other.fmt
+        self.Filter_name = other.fmt
+        self.post_treat = other.post_treat
+        self._name = other._name
+
+    def out(self, message, level=None):
+        """Actually log the message
+
+        @param message: formatted message
+        """
+        print message
 
     def log(self, level, message):
         """Print message
@@ -48,9 +67,9 @@
         try:
             formatted = self.format(level, message)
             if self.post_treat is None:
-                print formatted
+                self.out(formatted, level)
             else:
-                print self.post_treat(level, formatted)
+                self.out(self.post_treat(level, formatted), level)
         except Filtered:
             pass
 
@@ -61,7 +80,7 @@
         @param message: message to format
         @return: formatted message
 
-        @raise: Filtered the message must not be logged
+        @raise: Filtered when the message must not be logged
         """
         if self.fmt is None and self.filter_name is None:
             return message
@@ -75,7 +94,7 @@
         except AttributeError:
             if self.filter_name is not None:
                 raise ValueError("Bad filter: filters must have a .filter method")
-        return self.fmt % record
+        return self.fmt % record if self.fmt is not None else message
 
     def debug(self, msg):
         self.log(C.LOG_LVL_DEBUG, msg)
@@ -93,6 +112,23 @@
         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"""
 
@@ -152,145 +188,376 @@
         out = message
     return ''.join(out)
 
-def _manageOutputs(outputs_raw):
-    """ Parse output option in a backend agnostic way, and fill _handlers consequently
+
+class Configure(object):
+    LOGGER_CLASS = None
 
-    @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()
+    def __init__(self, level=None, fmt=None, output=None, logger=None, colors=False, force_colors=False):
+        """Configure 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"
+            - "levelname"
+            - "name" (logger name)
+        @param logger: if set, use it as a regular expression to filter on logger name.
+            Use search to match expression, so ^ or $ can be necessary.
+        @param colors: if True use ANSI colors to show log levels
+        @param force_colors: if True ANSI colors are used even if stdout is not a tty
+        """
+        self.preTreatment()
+        self.configureLevel(level)
+        self.configureFormat(fmt)
+        self.configureOutput(output)
+        self.configureLogger(logger)
+        self.configureColors(colors, force_colors)
+        self.postTreatment()
+        self.updateCurrentLogger()
+
+    def updateCurrentLogger(self):
+        """update existing logger to the class needed for this backend"""
+        if self.LOGGER_CLASS is None:
+            return
+        for name, logger in _loggers.items():
+            _loggers[name] = self.LOGGER_CLASS(logger)
+
+    def preTreatment(self):
+        pass
+
+    def configureLevel(self, level):
+        pass
 
-    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
+    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
 
-        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)
+        @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[output] = 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)
+            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
-            except (TypeError, ValueError):
-                limit = C.LOG_OPT_OUTPUT_MEMORY_LIMIT
-            _handlers[output] = limit
+            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})
+
 
-        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)
+            def dev_null(self, msg):
+                pass
+            for _level in C.LOG_LEVELS[:level_idx]:
+                setattr(Logger, _level.lower(), dev_null)
+
+    def configureFormat(self, fmt):
+        if fmt is not None:
+            if fmt != '%(message)s': # %(message)s is the same as None
+                Logger.fmt = fmt
+
+    def configureOutput(self, output):
+        if output is not None:
+            if output != C.LOG_OPT_OUTPUT_SEP + C.LOG_OPT_OUTPUT_DEFAULT:
+                # TODO: manage other outputs
+                raise NotImplementedError("Basic backend only manage default output yet")
+
+    def configureLogger(self, logger):
+        if logger:
+            Logger.filter_name = FilterName(logger)
 
-def _configureStdLogging(logging, level=None, fmt=C.LOG_OPT_FORMAT[1], output=C.LOG_OPT_OUTPUT[1], logger=None, colors=False, force_colors=False):
-    """Configure standard logging module
+    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")
+
+
+class ConfigureTwisted(ConfigureBasic):
+    LOGGER_CLASS = TwistedLogger
+
+    def changeObserver(self, observer, can_color=False):
+        """Install a hook on observer to manage SàT specificities
 
-    @param logging: standard logging module
-    @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"
-        - "levelname"
-        - "name" (logger name)
-    @param logger: if set, use it as a regular expression to filter on logger name.
-        Use search to match expression, so ^ or $ can be necessary.
-    @param colors: if True use ANSI colors to show log levels
-    @param force_colors: if True ANSI colors are used even if stdout is not a tty
-    """
-    format_ = fmt
-    if level is None:
-        level = C.LOG_LVL_DEBUG
-    import sys
-    with_color = colors & (sys.stdout.isatty() or force_colors)
-    if not colors and force_colors:
-        raise ValueError("force_colors can't be used if colors is False")
+        @param observer: original observer to hook
+        @param can_color: 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_color 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_color = log_file.isatty()
+        except AttributeError:
+            can_color = False
+        return self.changeObserver(observer, can_color=can_color)
+
+    def installObserverHook(self, observer):
+        """Check observer type and install SàT hook when possible
 
-    class SatFormatter(logging.Formatter):
-        u"""Formatter which manage SàT specificities"""
-
-        def __init__(self, fmt=None, datefmt=None):
-            super(SatFormatter, self).__init__(fmt, datefmt)
-
-        def format(self, record):
-            s = super(SatFormatter, self).format(record)
-            if with_color:
-                s = _ansiColors(record.levelname, s)
-            return s
+        @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_color=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
 
-    root_logger = logging.getLogger()
-    if len(root_logger.handlers) == 0:
-        _manageOutputs(output)
-        formatter = SatFormatter(format_)
-        name_filter = FilterName(logger) if logger else None
-        for handler, options in _handlers.items():
-            if handler == C.LOG_OPT_OUTPUT_DEFAULT:
-                hdlr = logging.StreamHandler()
-            elif handler == C.LOG_OPT_OUTPUT_MEMORY:
-                import logging.handlers
-                hdlr = logging.handlers.BufferingHandler(options)
-                _handlers[handler] = hdlr # we keep a reference to the handler to read the buffer later
-            elif handler == C.LOG_OPT_OUTPUT_FILE:
-                import os.path
-                hdlr = logging.FileHandler(os.path.expanduser(options))
+    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:
-                raise ValueError("Unknown handler type")
-            hdlr.setFormatter(formatter)
-            root_logger.addHandler(hdlr)
-            root_logger.setLevel(level)
-            if name_filter is not None:
-                hdlr.addFilter(name_filter)
-    else:
-        root_logger.warning(u"Handlers already set on root logger")
+                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 ConfigureStandard(Configure):
+
+    def __init__(self, level=None, fmt=C.LOG_OPT_FORMAT[1], output=C.LOG_OPT_OUTPUT[1], logger=None, colors=False, force_colors=False):
+        super(ConfigureStandard, self).__init__(level, fmt, output, logger, colors, force_colors)
 
-def _configureBasic(level=None, fmt=None, output=None, logger=None, colors=False, force_colors=False):
-    """Configure basic backend
-    @param level: same as _configureStdLogging.level
-    @param fmt: same as _configureStdLogging.fmt
-    @param output: not implemented yet TODO
-    @param logger: same as _configureStdLogging.logger
-    @param colors: same as _configureStdLogging.colors
-    @param force_colors: same as _configureStdLogging.force_colors
-    """
-    if level is not None:
-        # we deactivate methods below level
-        level_idx = C.LOG_LEVELS.index(level)
-        def dev_null(self, msg):
-            pass
-        for _level in C.LOG_LEVELS[:level_idx]:
-            setattr(Logger, _level.lower(), dev_null)
-    if fmt is not None:
-        if fmt != '%(message)s': # %(message)s is the same as None
-            Logger.fmt = fmt
-    if output is not None:
-        if output != C.LOG_OPT_OUTPUT_SEP + C.LOG_OPT_OUTPUT_DEFAULT:
-            # TODO: manage other outputs
-            raise NotImplementedError("Basic backend only manage default output yet")
+    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
+        format_ = fmt
+
+        class SatFormatter(logging.Formatter):
+            u"""Formatter which manage SàT specificities"""
+
+            def __init__(self, fmt=None, datefmt=None):
+                super(SatFormatter, self).__init__(fmt, datefmt)
+
+            def format(self, record):
+                s = super(SatFormatter, self).format(record)
+                if self.with_color:
+                    s = _ansiColors(record.levelname, s)
+                return s
+
+        self.formatter = SatFormatter(format_)
 
-    if logger:
-        Logger.filter_name = FilterName(logger)
+    def configureOutput(self, output):
+        self.manageOutputs(output)
 
-    if colors:
+    def configureLogger(self, logger):
+        self.name_filter = FilterName(logger) if logger else None
+
+    def configureColors(self, colors, force_colors):
         import sys
-        if force_colors or sys.stdout.isatty():
-            # 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")
+        self.with_color = colors & (sys.stdout.isatty() or 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):
+        hdlr.setFormatter(self.formatter)
+        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()
+                    self._addHandler(root_logger, hdlr)
+                elif handler == C.LOG_OPT_OUTPUT_MEMORY:
+                    import logging.handlers
+                    hdlr = logging.handlers.BufferingHandler(options)
+                    _handlers[handler] = hdlr # we keep a reference to the handler to read the buffer later
+                    self._addHandler(root_logger, hdlr)
+                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)
+                else:
+                    raise ValueError("Unknown handler type")
+        else:
+            root_logger.warning(u"Handlers already set on root logger")
+
 
 def configure(backend=C.LOG_BACKEND_STANDARD, **options):
     """Configure logging behaviour
@@ -304,28 +571,14 @@
         raise exceptions.InternalError("Logging can only be configured once")
     _backend = backend
 
-    if backend in (C.LOG_BACKEND_TWISTED, C.LOG_BACKEND_STANDARD):
-        if backend ==  C.LOG_BACKEND_TWISTED:
-            from twisted.python import log
-            observer = log.PythonLoggingObserver()
-            observer.start()
-        global getLogger
-        global debug
-        global info
-        global warning
-        global error
-        global critical
-        import logging
-        _configureStdLogging(logging, **options)
-        getLogger = logging.getLogger
-        debug = logging.debug
-        info = logging.info
-        warning = logging.warning
-        error = logging.error
-        critical = logging.critical
+    if backend == C.LOG_BACKEND_BASIC:
+        ConfigureBasic(**options)
 
-    elif backend == C.LOG_BACKEND_BASIC:
-        _configureBasic(**options)
+    elif backend == C.LOG_BACKEND_TWISTED:
+        ConfigureTwisted(**options)
+
+    elif backend == C.LOG_BACKEND_STANDARD:
+        ConfigureStandard(**options)
 
     else:
         raise ValueError("unknown backend")
@@ -375,7 +628,13 @@
     configure(backend, **log_conf)
 
 def getLogger(name=C.LOG_BASE_LOGGER):
-    return _loggers.setdefault(name, Logger(name))
+    if _backend in (None, C.LOG_BACKEND_BASIC):
+        logger_class = Logger
+    elif _backend == C.LOG_BACKEND_TWISTED:
+        logger_class = TwistedLogger
+    else:
+        raise ValueError("This method should not be called with backend [%s]" % _backend)
+    return _loggers.setdefault(name, logger_class(name))
 
 _root_logger = getLogger()