import abc import inspect import os import sys import threading as _threading from datetime import datetime from functools import wraps from typing import Any, Optional, Tuple, Union from .cli_base import CliOptions from .console import (WHITE, WARN, ERROR, RED, YELLOW, foreground as _fc, pp as _p, pc as _c) from .sys import PID as _PID_ _RUNTIME_COMPILE = False _PPID_ = os.environ.get('BPS_PARENT_PID') if _PPID_ is None: _PPID_ = _PID_ else: try: _PPID_ = int(_PPID_) + 1 except ValueError: _PPID_ = _PID_ _PID = _p(_PID_, _fc(int(_PPID_)), ']') _HEADER_ = os.environ.get('BPS_LOG_HEADER') STYLE_QUIET = 'quiet' STYLE_DEFAULT = 'default' STYLE_SIMPLE = 'simple' STYLE_SYSTEMD = 'systemd' if _HEADER_ is None: _HEADER_ = STYLE_DEFAULT class LoggerOptions(CliOptions): STYLE_QUIET = 'quiet' STYLE_DEFAULT = 'default' STYLE_SIMPLE = 'simple' STYLE_SYSTEMD = 'systemd' def __init__(self): if _RUNTIME_COMPILE: self.log_level = 1 else: self.log_level = 3 self.log_header_style = _HEADER_ class Logger(metaclass=abc.ABCMeta): """abstract class for Logger-able class""" LEVEL_VERBOSE = 3 LEVEL_INFO = 2 LEVEL_WARN = 1 LEVEL_ERROR = 0 LEVEL_QUIET = -1 FORMATTER: Optional['LoggerFormatter'] = None OPTIONS = LoggerOptions() __slots__ = () def log_verbose(self, *msg: Any) -> None: """log at verbose level""" self.get_formatter().log_verbose(*msg) def log_info(self, *msg: Any) -> None: """log at information level""" self.get_formatter().log_info(*msg) def log_warn(self, *msg: Any) -> None: """log at warning level""" self.get_formatter().log_warn(*msg) def log_error(self, *msg: Any) -> None: """log at error level""" self.get_formatter().log_error(*msg) @classmethod def set_formatter(cls, style: str): cls.OPTIONS.log_header_style = style cls.FORMATTER = None @classmethod def get_formatter(cls) -> 'LoggerFormatter': if cls.FORMATTER is None: style = cls.OPTIONS.log_header_style if style == LoggerOptions.STYLE_QUIET: cls.FORMATTER = NullLoggerFormatter() elif style == LoggerOptions.STYLE_SIMPLE: cls.FORMATTER = SimpleLoggerFormatter() elif style == LoggerOptions.STYLE_DEFAULT: cls.FORMATTER = DefaultLoggerFormatter() elif style == LoggerOptions.STYLE_SYSTEMD: cls.FORMATTER = SystemdLoggerFormatter() else: cls.FORMATTER = SimpleLoggerFormatter() return cls.FORMATTER class LoggerFormatter(Logger, metaclass=abc.ABCMeta): """Server with Logger function. PID process ID LEVEL log level, there are ===== ========= level text ===== ========= 0 ERROR 1 WARN 2 INFO 3 VERBOSE ===== ========= THREAD :class:`DataServerThread` name register to :class:`DataServer` HEADER or scope, indicate this message is under which class. """ TEXT_VERBOSE = 'VERB' TEXT_INFO = 'INFO' TEXT_WARN = 'WARN' TEXT_ERROR = 'ERROR' HEADER_VERBOSE = _p(TEXT_VERBOSE, None, ']') """verbose header""" HEADER_INFO = _p(TEXT_INFO, WHITE, ']') """info header""" HEADER_WARN = _p(TEXT_WARN, WARN, ']') """warn header""" HEADER_ERROR = _p(TEXT_ERROR, ERROR, ']') """error header""" __slots__ = '__log_level', def __init__(self): self.__log_level = Logger.OPTIONS.log_level def is_log_enable(self, level: int) -> bool: return self.__log_level >= level def set_log_level(self, level: int): self.__log_level = level @property def log_current_thread(self) -> str: thread = _threading.current_thread() # for unknown bug, the instance of ServerThread # may get result False when call isinstance(instance, ServerThread) # get but result True when call isinstance(instance, Thread). if hasattr(thread, 'log_header'): return thread.log_header elif thread.name == 'MainThread': return _p('main', RED, ']') else: return _p(thread.name, ']') @classmethod def _repr(cls, *msg: Any) -> str: return ' '.join(map(cls.__repr, msg)) @staticmethod def __repr(msg: Any) -> str: if callable(msg): msg = msg() return str(msg) @abc.abstractmethod def log_verbose(self, *msg: Any) -> None: pass @abc.abstractmethod def log_info(self, *msg: Any) -> None: pass @abc.abstractmethod def log_warn(self, *msg: Any) -> None: pass @abc.abstractmethod def log_error(self, *msg: Any) -> None: pass class NullLoggerFormatter(LoggerFormatter): """null logger formatter, drop all message. """ def log_verbose(self, *msg: Any) -> None: pass def log_info(self, *msg: Any) -> None: pass def log_warn(self, *msg: Any) -> None: pass def log_error(self, *msg: Any) -> None: pass class SimpleLoggerFormatter(LoggerFormatter): """simple logger formatter. **logging style** :: datetime [LEVEL] message """ def log_verbose(self, *msg: Any) -> None: if self.is_log_enable(3): print(datetime.now(), self.HEADER_VERBOSE, self._repr(*msg)) def log_info(self, *msg: Any) -> None: if self.is_log_enable(2): print(datetime.now(), self.HEADER_INFO, self._repr(*msg)) def log_warn(self, *msg: Any) -> None: if self.is_log_enable(1): print(datetime.now(), self.HEADER_WARN, self._repr(*msg)) def log_error(self, *msg: Any) -> None: print(datetime.now(), self.HEADER_ERROR, self._repr(*msg)) class DefaultLoggerFormatter(LoggerFormatter): """default logger formatter. **logging field** :: datetime [PID] [LEVEL] [THREAD] [HEADER]* message """ def log_verbose(self, *msg: Any) -> None: if self.is_log_enable(3): print(datetime.now(), _PID, self.HEADER_VERBOSE, self.log_current_thread, self._repr(*msg)) def log_info(self, *msg: Any) -> None: if self.is_log_enable(2): try: print(datetime.now(), _PID, self.HEADER_INFO, self.log_current_thread, self._repr(*msg)) finally: sys.stdout.flush() def log_warn(self, *msg: Any) -> None: if self.is_log_enable(1): try: print(datetime.now(), _PID, self.HEADER_WARN, self.log_current_thread, self._repr(*msg)) finally: sys.stdout.flush() def log_error(self, *msg: Any) -> None: try: print(datetime.now(), _PID, self.HEADER_ERROR, self.log_current_thread, self._repr(*msg)) finally: sys.stdout.flush() class SystemdLoggerFormatter(LoggerFormatter): """logger formatter used in systemd environment. which system logger service already record PID and datetime information. **logging field** :: [LEVEL] [THREAD] [HEADER]* message """ def log_verbose(self, *msg: Any) -> None: if self.is_log_enable(3): print(self.HEADER_VERBOSE, self.log_current_thread, self._repr(*msg)) def log_info(self, *msg: Any) -> None: if self.is_log_enable(2): try: print(self.HEADER_INFO, self.log_current_thread, self._repr(*msg)) finally: sys.stdout.flush() def log_warn(self, *msg: Any) -> None: if self.is_log_enable(1): try: print(self.HEADER_WARN, self.log_current_thread, self._repr(*msg)) finally: sys.stdout.flush() def log_error(self, *msg: Any) -> None: try: print(self.HEADER_ERROR, self.log_current_thread, self._repr(*msg)) finally: sys.stdout.flush() class LoggerFlag(Logger): """logger unit. subclass inherit this class can disable all the logging message by log_enable. all the message will prepend a log_header field. """ # __slots__ = ('_log_name', '__log_header', '__level', '__enable') def __init__(self, name: str, header: Union[str, int, Tuple[Any, ...]] = None, level=3): """ :param name: logger name :param header: logger header, str or tuple as parameter pass to cli_p """ self._log_name = name if header is None: header = _p(name, ']') elif isinstance(header, str): pass elif isinstance(header, int): header = _p(name, header, ']') else: header = _p(name, *header) self.__log_header = header self.__level = level self.__enable = True @property def log_name(self) -> str: return self._log_name @property def log_header(self) -> str: return self.__log_header @property def log_level(self) -> int: return self.__level def set_log_level(self, level: int): """set the logger level. The reason why we use method instead of property setter is that parent LoggerFlag can also set the level to its composed children LoggerFlags. :param level: """ self.__level = level @property def log_enable(self) -> bool: return self.__enable @log_enable.setter def log_enable(self, value: bool): self.__enable = value def is_log_enable(self, level: int) -> bool: return self.__enable and self.__level >= level def log_verbose(self, *msg: Any) -> None: """log at verbose level""" if self.is_log_enable(3): self.get_formatter().log_verbose(self.log_header, *msg) def log_info(self, *msg: Any) -> None: """log at information level""" if self.is_log_enable(2): self.get_formatter().log_info(self.log_header, *msg) def log_warn(self, *msg: Any) -> None: """log at warning level""" if self.is_log_enable(1): self.get_formatter().log_warn(self.log_header, *msg) def log_error(self, *msg: Any) -> None: """log at error level""" self.get_formatter().log_error(self.log_header, *msg) def _unpack(s: inspect.Signature, *args, **kwargs): def _return(): b: inspect.BoundArguments = s.bind_partial(None, *args, **kwargs) ret = [] for name, para in s.parameters.items(): # type: str, inspect.Parameter if name in ('self', 'cls'): continue try: a = b.arguments[name] except KeyError: pass else: if callable(a): ret.append('%s=%s' % (name, a.__name__)) else: ret.append('%s=%s' % (name, str(a))) return ' '.join(ret) return _return def logging_verbose(f): """decorator for logging method call""" if _RUNTIME_COMPILE: return f s = inspect.signature(f) @wraps(f) def _logger(self, *args, **kwargs): if isinstance(self, Logger): logger = self else: logger = Logger.get_formatter() if _RUNTIME_COMPILE: logger.log_verbose(f.__name__) else: logger.log_verbose(f.__name__, _unpack(s, *args, **kwargs)) return f(self, *args, **kwargs) return _logger def logging_info(f): """decorator for logging method call""" if _RUNTIME_COMPILE: return f s = inspect.signature(f) @wraps(f) def _logger(self, *args, **kwargs): if isinstance(self, Logger): logger = self else: logger = Logger.get_formatter() if _RUNTIME_COMPILE: logger.log_verbose(_c(f.__name__, YELLOW)) else: logger.log_info(_c(f.__name__, YELLOW), _unpack(s, *args, **kwargs)) return f(self, *args, **kwargs) return _logger def logging_warning(f): """decorator for logging method call""" s = inspect.signature(f) @wraps(f) def _logger(self, *args, **kwargs): if isinstance(self, Logger): logger = self else: logger = Logger.get_formatter() if _RUNTIME_COMPILE: logger.log_verbose(_c(f.__name__, YELLOW)) else: logger.log_warn(_c(f.__name__, YELLOW), _unpack(s, *args, **kwargs)) return f(self, *args, **kwargs) return _logger def logging_error(f): """decorator for logging method call""" s = inspect.signature(f) @wraps(f) def _logger(self, *args, **kwargs): if isinstance(self, Logger): logger = self else: logger = Logger.get_formatter() if _RUNTIME_COMPILE: logger.log_verbose(_c(f.__name__, RED)) else: logger.log_error(_c(f.__name__, RED), _unpack(s, *args, **kwargs)) return f(self, *args, **kwargs) return _logger