[ENH] add a new logger and delete the old one

abl/utils/__init__.py

@@ -0,0 +1,2 @@
+from .logger import ABLLogger
+from .utils import *

abl/utils/logger.py

@@ -0,0 +1,313 @@
+# Copyright (c) OpenMMLab. All rights reserved.
+import logging
+import os
+import os.path as osp
+import sys
+from logging import Logger, LogRecord
+from typing import Optional, Union
+
+from termcolor import colored
+
+from .manager import ManagerMixin, _accquire_lock, _release_lock
+
+
+class FilterDuplicateWarning(logging.Filter):
+    """Filter the repeated warning message.
+
+    Args:
+        name (str): name of the filter.
+    """
+
+    def __init__(self, name: str = "abl"):
+        super().__init__(name)
+        self.seen: set = set()
+
+    def filter(self, record: LogRecord) -> bool:
+        """Filter the repeated warning message.
+
+        Args:
+            record (LogRecord): The log record.
+
+        Returns:
+            bool: Whether to output the log record.
+        """
+        if record.levelno != logging.WARNING:
+            return True
+
+        if record.msg not in self.seen:
+            self.seen.add(record.msg)
+            return True
+        return False
+
+
+class ABLFormatter(logging.Formatter):
+    """Colorful format for ABLLogger. If the log level is error, the logger will
+    additionally output the location of the code.
+
+    Args:
+        color (bool): Whether to use colorful format. filehandler is not
+            allowed to use color format, otherwise it will be garbled.
+        blink (bool): Whether to blink the ``INFO`` and ``DEBUG`` logging
+            level.
+        **kwargs: Keyword arguments passed to
+            :meth:`logging.Formatter.__init__`.
+    """
+
+    _color_mapping: dict = dict(
+        ERROR="red", WARNING="yellow", INFO="white", DEBUG="green"
+    )
+
+    def __init__(self, color: bool = True, blink: bool = False, **kwargs):
+        super().__init__(**kwargs)
+        assert not (
+            not color and blink
+        ), "blink should only be available when color is True"
+        # Get prefix format according to color.
+        error_prefix = self._get_prefix("ERROR", color, blink=True)
+        warn_prefix = self._get_prefix("WARNING", color, blink=True)
+        info_prefix = self._get_prefix("INFO", color, blink)
+        debug_prefix = self._get_prefix("DEBUG", color, blink)
+
+        # Config output format.
+        self.err_format = (
+            f"%(asctime)s - %(name)s - {error_prefix} - "
+            "%(pathname)s - %(funcName)s - %(lineno)d - "
+            "%(message)s"
+        )
+        self.warn_format = f"%(asctime)s - %(name)s - {warn_prefix} - %(" "message)s"
+        self.info_format = f"%(asctime)s - %(name)s - {info_prefix} - %(" "message)s"
+        self.debug_format = f"%(asctime)s - %(name)s - {debug_prefix} - %(" "message)s"
+
+    def _get_prefix(self, level: str, color: bool, blink=False) -> str:
+        """Get the prefix of the target log level.
+
+        Args:
+            level (str): log level.
+            color (bool): Whether to get colorful prefix.
+            blink (bool): Whether the prefix will blink.
+
+        Returns:
+            str: The plain or colorful prefix.
+        """
+        if color:
+            attrs = ["underline"]
+            if blink:
+                attrs.append("blink")
+            prefix = colored(level, self._color_mapping[level], attrs=attrs)
+        else:
+            prefix = level
+        return prefix
+
+    def format(self, record: LogRecord) -> str:
+        """Override the `logging.Formatter.format`` method `. Output the
+        message according to the specified log level.
+
+        Args:
+            record (LogRecord): A LogRecord instance represents an event being
+                logged.
+
+        Returns:
+            str: Formatted result.
+        """
+        if record.levelno == logging.ERROR:
+            self._style._fmt = self.err_format
+        elif record.levelno == logging.WARNING:
+            self._style._fmt = self.warn_format
+        elif record.levelno == logging.INFO:
+            self._style._fmt = self.info_format
+        elif record.levelno == logging.DEBUG:
+            self._style._fmt = self.debug_format
+
+        result = logging.Formatter.format(self, record)
+        return result
+
+
+class ABLLogger(Logger, ManagerMixin):
+    """Formatted logger used to record messages.
+
+    ``ABLLogger`` can create formatted logger to log message with different
+    log levels and get instance in the same way as ``ManagerMixin``.
+    ``ABLLogger`` has the following features:
+
+    - Distributed log storage, ``ABLLogger`` can choose whether to save log of
+      different ranks according to `log_file`.
+    - Message with different log levels will have different colors and format
+      when displayed on terminal.
+
+    Note:
+        - The `name` of logger and the ``instance_name`` of ``ABLLogger`` could
+          be different. We can only get ``ABLLogger`` instance by
+          ``ABLLogger.get_instance`` but not ``logging.getLogger``. This feature
+          ensures ``ABLLogger`` will not be incluenced by third-party logging
+          config.
+        - Different from ``logging.Logger``, ``ABLLogger`` will not log warning
+          or error message without ``Handler``.
+
+    Examples:
+        >>> logger = ABLLogger.get_instance(name='ABLLogger',
+        >>>                                logger_name='Logger')
+        >>> # Although logger has name attribute just like `logging.Logger`
+        >>> # We cannot get logger instance by `logging.getLogger`.
+        >>> assert logger.name == 'Logger'
+        >>> assert logger.instance_name = 'ABLLogger'
+        >>> assert id(logger) != id(logging.getLogger('Logger'))
+        >>> # Get logger that do not store logs.
+        >>> logger1 = ABLLogger.get_instance('logger1')
+        >>> # Get logger only save rank0 logs.
+        >>> logger2 = ABLLogger.get_instance('logger2', log_file='out.log')
+        >>> # Get logger only save multiple ranks logs.
+        >>> logger3 = ABLLogger.get_instance('logger3', log_file='out.log',
+        >>>                                 distributed=True)
+
+    Args:
+        name (str): Global instance name.
+        logger_name (str): ``name`` attribute of ``Logging.Logger`` instance.
+            If `logger_name` is not defined, defaults to 'abl'.
+        log_file (str, optional): The log filename. If specified, a
+            ``FileHandler`` will be added to the logger. Defaults to None.
+        log_level (str): The log level of the handler. Defaults to
+            'INFO'. If log level is 'DEBUG', distributed logs will be saved
+            during distributed training.
+        file_mode (str): The file mode used to open log file. Defaults to 'w'.
+        distributed (bool): Whether to save distributed logs, Defaults to
+            false.
+    """
+
+    def __init__(
+        self,
+        name: str,
+        logger_name="abl",
+        log_file: Optional[str] = None,
+        log_level: Union[int, str] = "INFO",
+        file_mode: str = "w"
+    ):
+        Logger.__init__(self, logger_name)
+        ManagerMixin.__init__(self, name)
+        if isinstance(log_level, str):
+            log_level = logging._nameToLevel[log_level]
+
+        stream_handler = logging.StreamHandler(stream=sys.stdout)
+        # `StreamHandler` record month, day, hour, minute, and second
+        # timestamp.
+        stream_handler.setFormatter(ABLFormatter(color=True, datefmt="%m/%d %H:%M:%S"))
+        stream_handler.setLevel(log_level)
+        stream_handler.addFilter(FilterDuplicateWarning(logger_name))
+        self.handlers.append(stream_handler)
+
+        if log_file is None:
+            import time
+            local_time = time.strftime("%Y%m%d_%H_%M_%S", time.localtime())
+
+            save_dir = os.path.join("results", local_time)
+            self.save_dir = save_dir
+            if not os.path.exists(save_dir):
+                os.makedirs(save_dir)
+            log_file = osp.join(save_dir, local_time + ".log")
+
+        file_handler = logging.FileHandler(log_file, file_mode)
+        file_handler.setFormatter(
+            ABLFormatter(color=False, datefmt="%Y/%m/%d %H:%M:%S")
+        )
+        file_handler.setLevel(log_level)
+        file_handler.addFilter(FilterDuplicateWarning(logger_name))
+        self.handlers.append(file_handler)
+        self._log_file = log_file
+
+    @property
+    def log_file(self):
+        return self._log_file
+
+    @classmethod
+    def get_current_instance(cls) -> "ABLLogger":
+        """Get latest created ``ABLLogger`` instance.
+
+        :obj:`ABLLogger` can call :meth:`get_current_instance` before any
+        instance has been created, and return a logger with the instance name
+        "abl".
+
+        Returns:
+            ABLLogger: Configured logger instance.
+        """
+        if not cls._instance_dict:
+            cls.get_instance("abl")
+        return super().get_current_instance()
+
+    def callHandlers(self, record: LogRecord) -> None:
+        """Pass a record to all relevant handlers.
+
+        Override ``callHandlers`` method in ``logging.Logger`` to avoid
+        multiple warning messages in DDP mode. Loop through all handlers of
+        the logger instance and its parents in the logger hierarchy. If no
+        handler was found, the record will not be output.
+
+        Args:
+            record (LogRecord): A ``LogRecord`` instance contains logged
+                message.
+        """
+        for handler in self.handlers:
+            if record.levelno >= handler.level:
+                handler.handle(record)
+
+    def setLevel(self, level):
+        """Set the logging level of this logger.
+
+        If ``logging.Logger.selLevel`` is called, all ``logging.Logger``
+        instances managed by ``logging.Manager`` will clear the cache. Since
+        ``ABLLogger`` is not managed by ``logging.Manager`` anymore,
+        ``ABLLogger`` should override this method to clear caches of all
+        ``ABLLogger`` instance which is managed by :obj:`ManagerMixin`.
+
+        level must be an int or a str.
+        """
+        self.level = logging._checkLevel(level)
+        _accquire_lock()
+        # The same logic as `logging.Manager._clear_cache`.
+        for logger in ABLLogger._instance_dict.values():
+            logger._cache.clear()
+        _release_lock()
+
+
+def print_log(
+    msg, logger: Optional[Union[Logger, str]] = None, level=logging.INFO
+) -> None:
+    """Print a log message.
+
+    Args:
+        msg (str): The message to be logged.
+        logger (Logger or str, optional): If the type of logger is
+        ``logging.Logger``, we directly use logger to log messages.
+            Some special loggers are:
+
+            - "silent": No message will be printed.
+            - "current": Use latest created logger to log message.
+            - other str: Instance name of logger. The corresponding logger
+              will log message if it has been created, otherwise ``print_log``
+              will raise a `ValueError`.
+            - None: The `print()` method will be used to print log messages.
+        level (int): Logging level. Only available when `logger` is a Logger
+            object, "current", or a created logger instance name.
+    """
+    if logger is None:
+        print(msg)
+    elif isinstance(logger, logging.Logger):
+        logger.log(level, msg)
+    elif logger == "silent":
+        pass
+    elif logger == "current":
+        logger_instance = ABLLogger.get_current_instance()
+        logger_instance.log(level, msg)
+    elif isinstance(logger, str):
+        # If the type of `logger` is `str`, but not with value of `current` or
+        # `silent`, we assume it indicates the name of the logger. If the
+        # corresponding logger has not been created, `print_log` will raise
+        # a `ValueError`.
+        if ABLLogger.check_instance_created(logger):
+            logger_instance = ABLLogger.get_instance(logger)
+            logger_instance.log(level, msg)
+        else:
+            raise ValueError(f"ABLLogger: {logger} has not been created!")
+    else:
+        raise TypeError(
+            "`logger` should be either a logging.Logger object, str, "
+            f'"silent", "current" or None, but got {type(logger)}'
+        )

abl/utils/manager.py

@@ -0,0 +1,169 @@
+# Copyright (c) OpenMMLab. All rights reserved.
+import inspect
+import threading
+import warnings
+from collections import OrderedDict
+from typing import Type, TypeVar
+
+_lock = threading.RLock()
+T = TypeVar('T')
+
+
+def _accquire_lock() -> None:
+    """Acquire the module-level lock for serializing access to shared data.
+
+    This should be released with _release_lock().
+    """
+    if _lock:
+        _lock.acquire()
+
+
+def _release_lock() -> None:
+    """Release the module-level lock acquired by calling _accquire_lock()."""
+    if _lock:
+        _lock.release()
+
+
+class ManagerMeta(type):
+    """The metaclass for global accessible class.
+
+    The subclasses inheriting from ``ManagerMeta`` will manage their
+    own ``_instance_dict`` and root instances. The constructors of subclasses
+    must contain the ``name`` argument.
+
+    Examples:
+        >>> class SubClass1(metaclass=ManagerMeta):
+        >>>     def __init__(self, *args, **kwargs):
+        >>>         pass
+        AssertionError: <class '__main__.SubClass1'>.__init__ must have the
+        name argument.
+        >>> class SubClass2(metaclass=ManagerMeta):
+        >>>     def __init__(self, name):
+        >>>         pass
+        >>> # valid format.
+    """
+
+    def __init__(cls, *args):
+        cls._instance_dict = OrderedDict()
+        params = inspect.getfullargspec(cls)
+        params_names = params[0] if params[0] else []
+        assert 'name' in params_names, f'{cls} must have the `name` argument'
+        super().__init__(*args)
+
+
+class ManagerMixin(metaclass=ManagerMeta):
+    """``ManagerMixin`` is the base class for classes that have global access
+    requirements.
+
+    The subclasses inheriting from ``ManagerMixin`` can get their
+    global instances.
+
+    Examples:
+        >>> class GlobalAccessible(ManagerMixin):
+        >>>     def __init__(self, name=''):
+        >>>         super().__init__(name)
+        >>>
+        >>> GlobalAccessible.get_instance('name')
+        >>> instance_1 = GlobalAccessible.get_instance('name')
+        >>> instance_2 = GlobalAccessible.get_instance('name')
+        >>> assert id(instance_1) == id(instance_2)
+
+    Args:
+        name (str): Name of the instance. Defaults to ''.
+    """
+
+    def __init__(self, name: str = '', **kwargs):
+        assert isinstance(name, str) and name, \
+            'name argument must be an non-empty string.'
+        self._instance_name = name
+
+    @classmethod
+    def get_instance(cls: Type[T], name: str, **kwargs) -> T:
+        """Get subclass instance by name if the name exists.
+
+        If corresponding name instance has not been created, ``get_instance``
+        will create an instance, otherwise ``get_instance`` will return the
+        corresponding instance.
+
+        Examples
+            >>> instance1 = GlobalAccessible.get_instance('name1')
+            >>> # Create name1 instance.
+            >>> instance.instance_name
+            name1
+            >>> instance2 = GlobalAccessible.get_instance('name1')
+            >>> # Get name1 instance.
+            >>> assert id(instance1) == id(instance2)
+
+        Args:
+            name (str): Name of instance. Defaults to ''.
+
+        Returns:
+            object: Corresponding name instance, the latest instance, or root
+            instance.
+        """
+        _accquire_lock()
+        assert isinstance(name, str), \
+            f'type of name should be str, but got {type(cls)}'
+        instance_dict = cls._instance_dict  # type: ignore
+        # Get the instance by name.
+        if name not in instance_dict:
+            instance = cls(name=name, **kwargs)  # type: ignore
+            instance_dict[name] = instance  # type: ignore
+        elif kwargs:
+            warnings.warn(
+                f'{cls} instance named of {name} has been created, '
+                'the method `get_instance` should not accept any other '
+                'arguments')
+        # Get latest instantiated instance or root instance.
+        _release_lock()
+        return instance_dict[name]
+
+    @classmethod
+    def get_current_instance(cls):
+        """Get latest created instance.
+
+        Before calling ``get_current_instance``, The subclass must have called
+        ``get_instance(xxx)`` at least once.
+
+        Examples
+            >>> instance = GlobalAccessible.get_current_instance()
+            AssertionError: At least one of name and current needs to be set
+            >>> instance = GlobalAccessible.get_instance('name1')
+            >>> instance.instance_name
+            name1
+            >>> instance = GlobalAccessible.get_current_instance()
+            >>> instance.instance_name
+            name1
+
+        Returns:
+            object: Latest created instance.
+        """
+        _accquire_lock()
+        if not cls._instance_dict:
+            raise RuntimeError(
+                f'Before calling {cls.__name__}.get_current_instance(), you '
+                'should call get_instance(name=xxx) at least once.')
+        name = next(iter(reversed(cls._instance_dict)))
+        _release_lock()
+        return cls._instance_dict[name]
+
+    @classmethod
+    def check_instance_created(cls, name: str) -> bool:
+        """Check whether the name corresponding instance exists.
+
+        Args:
+            name (str): Name of instance.
+
+        Returns:
+            bool: Whether the name corresponding instance exists.
+        """
+        return name in cls._instance_dict
+
+    @property
+    def instance_name(self) -> str:
+        """Get the name of instance.
+
+        Returns:
+            str: Name of instance.
+        """
+        return self._instance_name

abl/utils/plog.py

@@ -1,146 +0,0 @@
-# coding: utf-8
-# ================================================================#
-#   Copyright (C) 2020 Freecss All rights reserved.
-#
-#   File Name     ：plog.py
-#   Author        ：freecss
-#   Email         ：karlfreecss@gmail.com
-#   Created Date  ：2020/10/23
-#   Description   ：
-#
-# ================================================================#
-
-import time
-import logging
-import pickle as pk
-import os
-import functools
-
-global recorder
-recorder = None
-
-
-class ResultRecorder:
-    def __init__(self):
-        logging.basicConfig(level=logging.DEBUG, filemode="a")
-
-        self.result = {}
-        self.set_savefile()
-
-        logging.info("===========================================================")
-        logging.info("============= Result Recorder Version: 0.03 ===============")
-        logging.info("===========================================================\n")
-
-        pass
-
-    def set_savefile(self):
-        local_time = time.strftime("%Y%m%d_%H_%M_%S", time.localtime())
-
-        save_dir = os.path.join("results", local_time)
-        if not os.path.exists(save_dir):
-            os.makedirs(save_dir)
-        save_file_path = os.path.join(save_dir, "result.pk")
-        save_file = open(save_file_path, "wb")
-
-        self.save_dir = save_dir
-        self.save_file = save_file
-
-        filename = os.path.join(save_dir, "log.txt")
-        file_handler = logging.FileHandler(filename)
-        file_handler.setLevel(logging.DEBUG)
-        formatter = logging.Formatter("%(asctime)s - %(levelname)s: %(message)s")
-        file_handler.setFormatter(formatter)
-        logging.getLogger().addHandler(file_handler)
-
-    def print(self, *argv, screen=False):
-        info = ""
-        for data in argv:
-            info += str(data)
-        if screen:
-            print(info)
-        logging.info(info)
-
-    def print_result(self, *argv):
-        for data in argv:
-            info = "#Result# %s" % str(data)
-            logging.info(info)
-
-    def store(self, *argv):
-        for data in argv:
-            if data.find(":") < 0:
-                continue
-            label, data = data.split(":")
-            self.store_kv(label, data)
-
-    def write_result(self, *argv):
-        self.print_result(*argv)
-        self.store(*argv)
-
-    def store_kv(self, label, data):
-        self.result.setdefault(label, [])
-        self.result[label].append(data)
-
-    def write_kv(self, label, data):
-        self.print_result({label: data})
-        # self.print_result(label + ":" + str(data))
-        self.store_kv(label, data)
-
-    def dump(self, save_file=None):
-        if save_file is None:
-            save_file = self.save_file
-        pk.dump(self.result, save_file)
-
-    def clock(self, func):
-        @functools.wraps(func)
-        def clocked(*args, **kwargs):
-            t0 = time.perf_counter()
-            result = func(*args, **kwargs)
-            elapsed = time.perf_counter() - t0
-
-            name = func.__name__
-            # arg_str = ','.join(repr(arg) for arg in args)
-            # context = f"{name}: ({arg_str})=>({result}), cost {elapsed}s"
-            context = f"{name}: cost {elapsed}s"
-            self.write_kv("func:", context)
-
-            return result
-
-        return clocked
-
-    def __del__(self):
-        self.dump()
-
-
-def clocker(*argv):
-    global recorder
-    if recorder is None:
-        recorder = ResultRecorder()
-    return recorder.clock(*argv)
-
-
-def INFO(*argv, screen=False):
-    global recorder
-    if recorder is None:
-        recorder = ResultRecorder()
-    return recorder.print(*argv, screen=screen)
-
-
-def DEBUG(*argv, screen=False):
-    global recorder
-    if recorder is None:
-        recorder = ResultRecorder()
-    return recorder.print(*argv, screen=screen)
-
-
-def logger():
-    global recorder
-    if recorder is None:
-        recorder = ResultRecorder()
-    return recorder
-
-
-if __name__ == "__main__":
-    recorder = ResultRecorder()
-    recorder.write_kv("test", 1)
-    recorder.set_savefile(pk_dir="haha")
-    recorder.write_kv("test", 1)