#!/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 exceptions

_backend = None
_loggers = {}
_handlers = {}


class Filtered(Exception):
    pass


class Logger(object):
    """High level logging class"""
    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):
        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

        @param level: one of C.LOG_LEVELS
        @param message: message to format and print
        """
        try:
            formatted = self.format(level, message)
            if self.post_treat is None:
                self.out(formatted, level)
            else:
                self.out(self.post_treat(level, formatted), level)
        except Filtered:
            pass

    def format(self, level, message):
        """Format message according to Logger.fmt

        @param level: one of C.LOG_LEVELS
        @param message: message to format
        @return: formatted message

        @raise: Filtered when the message must not be logged
        """
        if self.fmt is None and self.filter_name is None:
            return message
        record = {'name': self._name,
                  'message': message,
                  'levelname': level,
                 }
        try:
            if not self.filter_name.dictFilter(record):
                raise Filtered
        except AttributeError:
            if self.filter_name is not None:
                raise ValueError("Bad filter: filters must have a .filter method")
        try:
            return self.fmt % record
        except TypeError:
            return message
        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()
                return self.fmt % record
            else:
                raise e


    def debug(self, msg):
        self.log(C.LOG_LVL_DEBUG, msg)

    def info(self, msg):
        self.log(C.LOG_LVL_INFO, msg)

    def warning(self, msg):
        self.log(C.LOG_LVL_WARNING, msg)

    def error(self, msg):
        self.log(C.LOG_LVL_ERROR, msg)

    def critical(self, msg):
        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"""

    def __init__(self, name_re):
        """Initialise name filter

        @param name_re: regular expression used to filter names (using search and not match)
        """
        assert name_re
        import re
        self.name_re = re.compile(name_re)

    def filter(self, record):
        if self.name_re.search(record.name) is not None:
            return 1
        return 0

    def dictFilter(self, dict_record):
        """Filter using a dictionary record

        @param dict_record: dictionary with at list a key "name" with logger name
        @return: True if message should be logged
        """
        class LogRecord(object):
            pass
        log_record = LogRecord()
        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):
    LOGGER_CLASS = None

    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

    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)
            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 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_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 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")


def configure(backend=C.LOG_BACKEND_STANDARD, **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
    """
    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)

    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]

    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
    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 getLogger(name=C.LOG_BASE_LOGGER):
    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()

def debug(msg):
    _root_logger.debug(msg)

def info(msg):
    _root_logger.info(msg)

def warning(msg):
    _root_logger.warning(msg)

def error(msg):
    _root_logger.error(msg)

def critical(msg):
    _root_logger.critical(msg)