Source code for Muscat.Helpers.Logger

# -*- coding: utf-8 -*-
#
# This file is subject to the terms and conditions defined in
# file 'LICENSE.txt', which is part of this source code package.
#
import logging
import time
import inspect

printCallerStack = True
printTime = True
try:
    import psutil

    printMemoryUsage = True
except ImportError:  # pragma: no cover
    printMemoryUsage = False

useDifferentialTime = True

_startTime: float = time.time()


class ContextFilter(logging.Filter):
    def __init__(self, name: str = "") -> None:
        super().__init__(name)
        self.silent = False

    @staticmethod
    def GetHeader():
        res = ""
        if printCallerStack:
            res += '  File "%(file)s", line %(line)-4i'

        if printTime:
            res += "[%(time)-s]"

        global printMemoryUsage
        if printMemoryUsage:
            res += " [%(memUsage)-.5f MB]"

        res += " %(levelname)s"

        if len(res) > 0:
            res += " --> "

        res += "%(message)s"
        return res

    def filter(self, record):
        if self.silent:
            return False

        if printTime:
            record.time = str(GetFormattedTime())

        if printCallerStack:
            stack = inspect.stack()[6]
            record.file = stack[1]
            record.line = stack[2]

        global printMemoryUsage
        if printMemoryUsage:
            record.memUsage = psutil.Process().memory_info().rss / (1048576)

        return True


def ResetStartTime() -> None:
    """
    Function to reset the start time of a program.

    """
    global _startTime
    _startTime = time.time()


def SetUseDifferentialTime(val: bool) -> None:
    """Function to set the printing format

    Parameters
    ----------
    val : bool
        True to print the time from the beginning of the program or False to print the current time, defaults to [True]
    """
    global useDifferentialTime
    useDifferentialTime = val


def SilentAllMuscatOutput():
    logger.setLevel(1000)
    for h in logger.handlers:
        h.setFormatter(defaultFormat)
    contextFilter.silent = True


def MinimalMuscatOutput():
    logger.setLevel(logging.CRITICAL)
    for h in logger.handlers:
        h.setFormatter(defaultFormat)
    contextFilter.silent = False


def DefaultMuscatOutput():
    logger.setLevel(logging.INFO + 1)
    for h in logger.handlers:
        h.setFormatter(defaultFormat)
    contextFilter.silent = False


def VerboseMuscatOutput():
    logger.setLevel(1)
    for h in logger.handlers:
        h.setFormatter(verboseFormat)
    contextFilter.silent = False

def SetMuscatLogLevel(logger_level):
    levels = (1, logging.INFO + 1, logging.CRITICAL,  1000)
    functions = (VerboseMuscatOutput, DefaultMuscatOutput, MinimalMuscatOutput, SilentAllMuscatOutput)
    from bisect import bisect
    index = bisect(levels,logger_level)
    if index == len(levels):
        functions[-1]()
    else:
        functions[index]()

def IsVerboseMuscatOutput():
    return logger.getEffectiveLevel() <= 10


def SetUpMuscatLogger(logger: logging.Logger):
    if logger.hasHandlers() == False:
        logger.addHandler(logging.StreamHandler())
    logger.addFilter(contextFilter)


# logging.basicConfig()#format=ContextFilter.GetHeader())
logger = logging.getLogger("Muscat")
contextFilter = ContextFilter()
verboseFormat = logging.Formatter(ContextFilter.GetHeader())
defaultFormat = logging.Formatter()

SetUpMuscatLogger(logger)
DefaultMuscatOutput()


def Debug(msg, *args, **kwargs):
    logger.debug(msg, *args, **kwargs)


def Info(msg, *args, **kwargs):
    logger.info(msg, *args, **kwargs)


def Warning(msg, *args, **kwargs):
    logger.warning(msg, *args, **kwargs)


def Error(msg, *args, **kwargs):
    logger.error(msg, *args, **kwargs)


def Critical(msg, *args, **kwargs):
    logger.critical(msg, *args, **kwargs)


def ForcePrint(msg, *args, **kwargs):
    print(msg)


def Print(msg, *args, **kwargs):
    print(msg)


def GetDiffTime():
    return time.time() - _startTime


def GetFormattedTime():
    if useDifferentialTime:
        return f"{GetDiffTime():10.7f}"
    else:
        m, s = divmod(time.time(), 60.0)
        h, m = divmod(m, 60)
        d, h = divmod(h, 24)

        return f"{(h+1):2.0f}:{m:2.0f}:{s:2.2f}"

class CatchLog(logging.Handler):
    """Class to capture the logger output
    To be used with a with :

        with Logger.CatchLog() as e:
            Logger.Warning("hello")
            assert e.messages['warning'][0] == "hello"
    """
    def __init__(self, *args, **kwargs):
        super().__init__( *args, **kwargs)
        self.reset()
    def reset(self):
        self.messages = {
            'debug': [],
            'info': [],
            'warning': [],
            'error': [],
            'critical': [],
        }
    def __enter__(self):
        logger.addHandler(self)
        self.logger_level_save = logger.getEffectiveLevel()
        VerboseMuscatOutput()
        return self

    def __exit__(self, *args):
        logger.removeHandler(self)
        SetMuscatLogLevel(self.logger_level_save)

    def emit(self, record):
        self.messages[record.levelname.lower()].append(record.getMessage())

def CheckIntegrity(GUI: bool = False):
    import Muscat.Helpers.Logger as Logger

    with Logger.CatchLog() as e:
        Logger.Warning("hello")
        assert e.messages['warning'][0] == "hello"

    print("Init CheckIntegrity Logger")
    Logger.Critical("() Hello Critical ()")  # 50
    Logger.Error("() Hello Error ()")  # 40
    Logger.Warning("() Hello Warning ()")  # 30
    Logger.Info("() Hello Info ()")  # 20
    Logger.Debug("() Hello Debug ()")  # 10
    Logger.IsVerboseMuscatOutput()
    # global logger
    # global useDifferentialTime
    # useDifferentialTime_save = Logger.useDifferentialTime

    # level_save = Logger.logger.getEffectiveLevel()
    logger_level_save = Logger.logger.getEffectiveLevel()

    try:
        # User code
        Logger.VerboseMuscatOutput()
        Logger.Critical("(Verbose) Hello Critical (Verbose)")  # 50
        Logger.Error("(Verbose) Hello Error (Verbose)")  # 40
        Logger.Warning("(Verbose) Hello Warning (Verbose)")  # 30
        Logger.Info(" (Verbose) Hello Info (Verbose)")  # 20
        Logger.Debug(" (Verbose) Hello Debug (Verbose)")  # 10

        printCallerStack = False
        printTime = False
        printMemoryUsage = False
        useDifferentialTime = False

        DefaultMuscatOutput()

        Logger.Critical("(Default) Hello Critical (Default)")  # 50
        Logger.Error("(Default) Hello Error (Default)")  # 40
        Logger.Warning("(Default) Hello Warning (Default)")  # 30
        Logger.Info("(Default) Hello Info (Default)")  # 20
        Logger.Debug("(Default) Hello Debug (Default)")  # 10

        Logger.MinimalMuscatOutput()
        Logger.Critical("(Minimal) Hello Critical (Minimal)")  # 50
        Logger.Error("(Minimal) Hello Error (Minimal)")  # 40
        Logger.Warning("(Minimal) Hello Warning (Minimal)")  # 30
        Logger.Info("(Minimal) Hello Info (Minimal)")  # 20
        Logger.Debug("(Minimal) Hello Debug (Minimal)")  # 10

        Logger.SilentAllMuscatOutput()
        print("Silent Begin")
        Logger.Critical("(Silent) Hello Critical (Silent)")  # 50
        Logger.Error("(Silent) Hello Error (Silent)")  # 40
        Logger.Warning("(Silent) Hello Warning (Silent)")  # 30
        Logger.Info("(Silent) Hello Info (Silent)")  # 20
        Logger.Debug("(Silent) Hello Debug (Silent)")  # 10
        Logger.Print("Output using Logger.Print() ")
        print("Silent end")

        Logger.GetFormattedTime()
        Logger.useDifferentialTime = not Logger.useDifferentialTime
        Logger.GetFormattedTime()
        Logger.useDifferentialTime = not Logger.useDifferentialTime

        Logger.DefaultMuscatOutput()
    finally:
        SetMuscatLogLevel(logger_level_save)

    global _startTime
    _startTime_save = _startTime
    Logger.ResetStartTime()
    _startTime = _startTime_save

    Logger.GetFormattedTime()
    Logger.SetUseDifferentialTime(not useDifferentialTime)
    Logger.GetFormattedTime()
    Logger.SetUseDifferentialTime(not useDifferentialTime)

    Logger.ForcePrint("Logger ForcePrint")


    return "ok"


if __name__ == "__main__":

    print(CheckIntegrity(GUI=True))  # pragma: no cover