qlib
qlib copied to clipboard
fix duplicate log
Fix duplicated log record issue.
Description
Set parent property propagate
of QlibLogger
to False.
Motivation and Context
If the official python logging
module is called somewhere during qlib run, after its call, the same qlib log record will get printed twice with different format, e.g. execute below code snippet
qlib.init()
logger = get_module_logger("mytest")
logger.info("normal")
logging.debug("directly call logging")
logger.info("see duplicate")
leads to below result (note the last two lines):
[300088:MainThread](2023-10-05 09:39:03,847) INFO - qlib.Initialization - [config.py:416] - default_conf: client.
[300088:MainThread](2023-10-05 09:39:04,548) INFO - qlib.Initialization - [__init__.py:74] - qlib successfully initialized based on client settings.
[300088:MainThread](2023-10-05 09:39:04,548) INFO - qlib.Initialization - [__init__.py:76] - data_path={'__DEFAULT_FREQ': WindowsPath('G:/qlib_data/cn_data')}
[300088:MainThread](2023-10-05 09:39:04,549) INFO - qlib.mytest - [log_debug.py:8] - normal
[300088:MainThread](2023-10-05 09:39:04,549) INFO - qlib.mytest - [log_debug.py:10] - see duplicate
INFO:qlib.mytest:see duplicate
After some investigation, found that the qlib logger organised with hierarchy <qlib.log.QlibLogger qlib.mytest (INFO)>-<logging.Logger qlib (DEBUG)>-><logging.RootLogger root (WARNING)>
, and the log record generated in QlibLogger is propagated to the <logging.Logger qlib (DEBUG)>
to be emitted. By default it will also be propagated to the root level, but by default root level has no handler so no emission occurs.
However, direct call of logging
will automatically add StreamHandler
to the RootLogger
, thus we see logger.info("see duplicate")
gets emitted twice.
Therefore to fix this we need to truncate the propagation at the second level.
How Has This Been Tested?
- [x] Pass the test by running:
pytest qlib/tests/test_all_pipeline.py
under upper directory ofqlib
. - [ ] If you are adding a new feature, test on your own test scripts.
Screenshots of Test Results (if appropriate):
- Pipeline test:
- Your own tests: After fix the code snippet gives:
[296660:MainThread](2023-10-05 10:08:41,651) INFO - qlib.Initialization - [config.py:416] - default_conf: client.
[296660:MainThread](2023-10-05 10:08:42,348) INFO - qlib.Initialization - [__init__.py:74] - qlib successfully initialized based on client settings.
[296660:MainThread](2023-10-05 10:08:42,349) INFO - qlib.Initialization - [__init__.py:76] - data_path={'__DEFAULT_FREQ': WindowsPath('G:/qlib_data/cn_data')}
[296660:MainThread](2023-10-05 10:08:42,349) INFO - qlib.mytest - [log_debug.py:8] - normal
[296660:MainThread](2023-10-05 10:08:42,349) INFO - qlib.mytest - [log_debug.py:10] - see duplicate
The duplicate record disappears.
Types of changes
- [x] Fix bugs
- [ ] Add new feature
- [ ] Update documentation