scikit-learn-intelex icon indicating copy to clipboard operation
scikit-learn-intelex copied to clipboard

[Bug] Logging messages, unable to change level of logging.

Open teabagk7 opened this issue 3 years ago • 4 comments

I use sklearnex to patch original sklearn. In my application I call KMeans from sklearn.cluster >50 times. And I have the next message every time: [INFO] sklearn.cluster.KMeans.fit: uses Intel(R) oneAPI Data Analytics Library solver

Both of the next solutions doesn't help to solve my problem: patch_sklearn(verbose=False) logging.getLogger("sklearnex").setLevel(logging.WARNING)

Could you please help me to fix this one?

teabagk7 avatar Apr 27 '21 16:04 teabagk7

It prints the message if you use env variable SKLEARNEX_VERBOSE=INFO. Just unset this. Refer to the documentation: https://intel.github.io/scikit-learn-intelex/verbose.html

SmirnovEgorRu avatar Apr 27 '21 19:04 SmirnovEgorRu

It prints the message if you use env variable SKLEARNEX_VERBOSE=INFO. Just unset this. Refer to the documentation: https://intel.github.io/scikit-learn-intelex/verbose.html

I don't use this variable.

teabagk7 avatar Apr 27 '21 22:04 teabagk7

It seems that if you use the python logging facilities, the env variable SKLEARNEX_VERBOSE does nothing.

Impementing a filter gives you some help to get rid of unnecessary log messages. Currently, I go with

logging.getLogger().addFilter(lambda record: 'running accelerated version on CPU' not in record.msg)
logging.getLogger().addFilter(lambda record: 'debugging for the patch is enabled to track the usage of Intel® oneAPI Data Analytics Library (oneDAL)' not in record.msg)
logging.getLogger().addFilter(lambda record: 'patching failed with cause - The shape of X does not satisfy oneDAL requirements: Number of features >= number of samples.' not in record.msg)
logging.getLogger().addFilter(lambda record: 'fallback to original Scikit-learn' not in record.msg)

which is a bit of an annoyance. Just NOT using the root logger, but having a specific intelx-logger would simplify this, and also speed up things, by quite a bunch.

el-hult avatar Mar 22 '22 10:03 el-hult

Okay. It seems the problem should be relatively simple to fix. In various files, such as https://github.com/intel/scikit-learn-intelex/blob/59fee38028c53bed0bcc3f259880603a997020d1/daal4py/sklearn/linear_model/_ridge.py

there is a simple import and then use of the root logger. E.g.

https://github.com/intel/scikit-learn-intelex/blob/59fee38028c53bed0bcc3f259880603a997020d1/daal4py/sklearn/monkeypatch/tests/utils/_launch_algorithms.py#L18

https://github.com/intel/scikit-learn-intelex/blob/59fee38028c53bed0bcc3f259880603a997020d1/daal4py/sklearn/monkeypatch/tests/utils/_launch_algorithms.py#L62

But one should really use named logger in this situation, as described in https://docs.python.org/3/library/logging.html?highlight=logging#logging.getLogger e.g.

import logging
logger = logging.getLogger('sklearnex.patch')
# ... do things
logger.info('fit')

Im not experienced in building this python package from source, so implementing a fix is a bit of a strech for me.

el-hult avatar Mar 22 '22 11:03 el-hult

2 years and no resolution? Very responsive.

fingoldo avatar Jan 31 '23 18:01 fingoldo

I wanted to silence the INFO messages while keeping the rest of the output. When I implement a classification pipeline from scratch patch_sklearn(verbose=False) seems to do the trick. When I use ATOM to build a pipeline the INFO messages won't go away. With some help from Chat-GTP I placed the following at the start of the cell and it worked:

logger = logging.getLogger()
logger.setLevel(logging.CRITICAL)
stream = io.StringIO()
handler = logging.StreamHandler(stream)
logger.addHandler(handler)

Hope this will help someone in case patch_sklearn(verbose=False) does not work! :)

MariosGvr avatar Apr 06 '23 17:04 MariosGvr

The suggestion from ChatGPT is quite roundabout. If you just want to surpress the logging facilities, I think logging.getLogger().setLevel('CRITICAL') should be fine. It depends a little on when you call patch_sklearn(verbose=True).

But in my case, I want the logging output. Just on another logger, not the default one.

el-hult avatar Apr 22 '23 14:04 el-hult

I might be able to implement this fix. Before putting down the work - would you consider a PR, @Alexsandruss ?

el-hult avatar Apr 22 '23 14:04 el-hult

I might be able to implement this fix. Before putting down the work - would you consider a PR, @Alexsandruss ?

If your idea is to move sklearnex logging to named logger, I'm not against implementation in PR. Most part of logging is done here, but there are some other places in sklearnex where it's used.

Alexsandruss avatar Apr 25 '23 13:04 Alexsandruss

Logging in sklearnex is controlled by named logger 'sklearnex' from now. Change of logging level can be done by logging.getLogger().setLevel(logging.WARNING) line, for example.

Alexsandruss avatar May 09 '23 21:05 Alexsandruss

Amazing. Well done!

el-hult avatar May 10 '23 07:05 el-hult