From 6a47416a2d21489578945ee085758608ed5e8bd2 Mon Sep 17 00:00:00 2001 From: YQ Tsui Date: Tue, 29 Nov 2022 08:09:22 +0800 Subject: [PATCH] Fix logging_level: make logging level specified in qlib.init applies to all loggers (#1368) * fix logging_level: make logging level specified in qlib.init apply to all loggers * downgrade loglevel in expmanager __init__ to debug (it will be called in each process in multiprocessing operations such as read data) * correct gramma error * fix black lint * use functor to cache loggers and set level * correct black lint * correct pylint * correct pylint --- .../developer/code_standard_and_dev_guide.rst | 2 +- qlib/__init__.py | 6 +-- qlib/config.py | 3 +- qlib/log.py | 51 +++++++++++-------- qlib/workflow/exp.py | 9 ++-- qlib/workflow/expm.py | 2 +- qlib/workflow/recorder.py | 3 +- 7 files changed, 42 insertions(+), 34 deletions(-) diff --git a/docs/developer/code_standard_and_dev_guide.rst b/docs/developer/code_standard_and_dev_guide.rst index 79a7778ad..87f193b8e 100644 --- a/docs/developer/code_standard_and_dev_guide.rst +++ b/docs/developer/code_standard_and_dev_guide.rst @@ -16,7 +16,7 @@ When you submit a PR request, you can check whether your code passes the CI test 1. Qlib will check the code format with black. The PR will raise error if your code does not align to the standard of Qlib(e.g. a common error is the mixed use of space and tab). - You can fix the bug by inputing the following code in the command line. + You can fix the bug by inputting the following code in the command line. .. code-block:: bash diff --git a/qlib/__init__.py b/qlib/__init__.py index 3a666c5be..61113244e 100644 --- a/qlib/__init__.py +++ b/qlib/__init__.py @@ -10,7 +10,7 @@ import yaml import logging import platform import subprocess -from .log import get_module_logger +from .log import get_module_logger, set_global_logger_level # init qlib @@ -34,8 +34,7 @@ def init(default_conf="client", **kwargs): from .config import C # pylint: disable=C0415 from .data.cache import H # pylint: disable=C0415 - # FIXME: this logger ignored the level in config - logger = get_module_logger("Initialization", level=logging.INFO) + logger = get_module_logger("Initialization") skip_if_reg = kwargs.pop("skip_if_reg", False) if skip_if_reg and C.registered: @@ -48,6 +47,7 @@ def init(default_conf="client", **kwargs): if clear_mem_cache: H.clear() C.set(default_conf, **kwargs) + get_module_logger.setLevel(C.logging_level) # mount nfs for _freq, provider_uri in C.provider_uri.items(): diff --git a/qlib/config.py b/qlib/config.py index 4b4123643..63773fcef 100644 --- a/qlib/config.py +++ b/qlib/config.py @@ -411,8 +411,7 @@ class QlibConfig(Config): if _logging_config: set_log_with_config(_logging_config) - # FIXME: this logger ignored the level in config - logger = get_module_logger("Initialization", level=logging.INFO) + logger = get_module_logger("Initialization", kwargs.get("logging_level", self.logging_level)) logger.info(f"default_conf: {default_conf}.") self.set_mode(default_conf) diff --git a/qlib/log.py b/qlib/log.py index a2fbde4b5..115abc137 100644 --- a/qlib/log.py +++ b/qlib/log.py @@ -48,33 +48,44 @@ class QlibLogger(metaclass=MetaLogger): return self.logger.__getattribute__(name) -def get_module_logger(module_name, level: Optional[int] = None) -> QlibLogger: - """ - Get a logger for a specific module. +class _QLibLoggerManager: + def __init__(self): + self._loggers = {} - :param module_name: str - Logic module name. - :param level: int - :return: Logger - Logger object. - """ - if level is None: - level = C.logging_level + def setLevel(self, level): + for logger in self._loggers.values(): + logger.setLevel(level) - if not module_name.startswith("qlib."): - # Add a prefix of qlib. when the requested ``module_name`` doesn't start with ``qlib.``. - # If the module_name is already qlib.xxx, we do not format here. Otherwise, it will become qlib.qlib.xxx. - module_name = "qlib.{}".format(module_name) + def __call__(self, module_name, level: Optional[int] = None) -> QlibLogger: + """ + Get a logger for a specific module. - # Get logger. - module_logger = QlibLogger(module_name) - module_logger.setLevel(level) - return module_logger + :param module_name: str + Logic module name. + :param level: int + :return: Logger + Logger object. + """ + if level is None: + level = C.logging_level + + if not module_name.startswith("qlib."): + # Add a prefix of qlib. when the requested ``module_name`` doesn't start with ``qlib.``. + # If the module_name is already qlib.xxx, we do not format here. Otherwise, it will become qlib.qlib.xxx. + module_name = "qlib.{}".format(module_name) + + # Get logger. + module_logger = self._loggers.setdefault(module_name, QlibLogger(module_name)) + module_logger.setLevel(level) + return module_logger + + +get_module_logger = _QLibLoggerManager() class TimeInspector: - timer_logger = get_module_logger("timer", level=logging.INFO) + timer_logger = get_module_logger("timer") time_marks = [] diff --git a/qlib/workflow/exp.py b/qlib/workflow/exp.py index 95e5db473..d0adda66e 100644 --- a/qlib/workflow/exp.py +++ b/qlib/workflow/exp.py @@ -4,13 +4,12 @@ from typing import Dict, List, Union from qlib.typehint import Literal import mlflow -import logging from mlflow.entities import ViewType from mlflow.exceptions import MlflowException from .recorder import Recorder, MLflowRecorder from ..log import get_module_logger -logger = get_module_logger("workflow", logging.INFO) +logger = get_module_logger("workflow") class Experiment: @@ -22,7 +21,7 @@ class Experiment: def __init__(self, id, name): self.id = id self.name = name - self.active_recorder = None # only one recorder can running each time + self.active_recorder = None # only one recorder can run each time self._default_rec_name = "abstract_recorder" def __repr__(self): @@ -232,7 +231,7 @@ class Experiment: Returns ------- - The return type depent on `rtype` + The return type depends on `rtype` if `rtype` == "dict": A dictionary (id -> recorder) of recorder information that being stored. elif `rtype` == "list": @@ -354,7 +353,7 @@ class MLflowExperiment(Experiment): Parameters ---------- max_results : int - the number limitation of the results + the number limitation of the results' status : str the criteria based on status to filter results. `None` indicates no filtering. diff --git a/qlib/workflow/expm.py b/qlib/workflow/expm.py index 3aaa574dd..be6b494e0 100644 --- a/qlib/workflow/expm.py +++ b/qlib/workflow/expm.py @@ -37,7 +37,7 @@ class ExpManager: self._active_exp_uri = None # No active experiments. So it is set to None self._default_exp_name = default_exp_name self.active_experiment = None # only one experiment can be active each time - logger.info(f"experiment manager uri is at {self.uri}") + logger.debug(f"experiment manager uri is at {self.uri}") def __repr__(self): return "{name}(uri={uri})".format(name=self.__class__.__name__, uri=self.uri) diff --git a/qlib/workflow/recorder.py b/qlib/workflow/recorder.py index 4b3fde20f..4d0fd8a23 100644 --- a/qlib/workflow/recorder.py +++ b/qlib/workflow/recorder.py @@ -5,7 +5,6 @@ import os import sys from typing import Optional import mlflow -import logging import shutil import pickle import tempfile @@ -20,7 +19,7 @@ from qlib.utils.paral import AsyncCaller from ..log import TimeInspector, get_module_logger from mlflow.store.artifact.azure_blob_artifact_repo import AzureBlobArtifactRepository -logger = get_module_logger("workflow", logging.INFO) +logger = get_module_logger("workflow") # mlflow limits the length of log_param to 500, but this caused errors when using qrun, so we extended the mlflow limit. mlflow.utils.validation.MAX_PARAM_VAL_LENGTH = 1000