peterlu14
538 lines
14 KiB
Python
538 lines
14 KiB
Python
import abc
|
|
import inspect
|
|
import os
|
|
import sys
|
|
import threading as _threading
|
|
from time import time
|
|
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
|
|
|
|
|
|
def calculate_time(time_limit=None):
|
|
def actual_calculate_time(func):
|
|
def warp(*args, **kwargs):
|
|
now = time()
|
|
func(*args, **kwargs)
|
|
if time_limit == None:
|
|
print(func.__name__,'cost:', time() - now)
|
|
else:
|
|
if time() - now > time_limit:
|
|
print(func.__name__,'cost:', time() - now)
|
|
return warp
|
|
return actual_calculate_time
|