Repository: matchms/matchms
Pull request #447 (2023-06-23 10:32:58)

rdkit log level implementation to supress warnings
I had a problem that when using matchms metadata filter functions, lower level rdkit logs would be shown.

Examples:
`[11:57:51] WARNING: Omitted undefined stereo`
`[12:31:27] WARNING: Charges were rearranged; Omitted undefined stereo`

To solve this I have implemented a function on matchms level that mimics [rdkit's set log level](https://github.com/rdkit/rdkit/blob/master/rdkit/RDLogger.py). The functionality of this is a bit above just warning supression since it allows you to set any rdkit log level you want. Avaliable log levels are read from rdkit so that they remain consistent.

I have also added a test in tests/test_metadata_utils.py that checks if all log messages are propagated correctly.


Patch:
diff --git a/matchms/__init__.py b/matchms/__init__.py
index d78128b8..3dacaa41 100644
--- a/matchms/__init__.py
+++ b/matchms/__init__.py
@@ -2,7 +2,8 @@ from . import exporting, filtering, importing, networking, plotting, similarity
 from .__version__ import __version__
 from .calculate_scores import calculate_scores
 from .Fragments import Fragments
-from .logging_functions import _init_logger, set_matchms_logger_level
+from .logging_functions import (_init_logger, set_matchms_logger_level,
+                                set_rdkit_logger_level)
 from .Metadata import Metadata
 from .Pipeline import Pipeline
 from .Scores import Scores
@@ -11,6 +12,22 @@ from .Spectrum import Spectrum
 
 _init_logger()
 
+try:  # rdkit is not included in pip package
+    from rdkit import Chem
+    set_rdkit_logger_level('rdApp.error')
+except ImportError:
+    _has_rdkit = False
+    from collections import UserString
+
+    class ChemMock(UserString):
+        def __call__(self, *args, **kwargs):
+            return self
+
+        def __getattr__(self, key):
+            return self
+
+    Chem = AllChem = ChemMock("")
+
 
 __author__ = "Netherlands eScience Center"
 __email__ = 'generalization@esciencecenter.nl'
diff --git a/matchms/logging_functions.py b/matchms/logging_functions.py
index 6394a80d..513fc8df 100644
--- a/matchms/logging_functions.py
+++ b/matchms/logging_functions.py
@@ -42,6 +42,15 @@ import logging.config
 import sys
 
 
+try:
+    from rdkit import RDLogger
+except ImportError:
+    _has_rdkit = False
+else:
+    _has_rdkit = True
+rdkit_missing_message = "Conda package 'rdkit' is required for this functionality."
+
+
 _formatter = logging.Formatter(
     '%(asctime)s:%(levelname)s:%(name)s:%(module)s:%(message)s')
 
@@ -121,3 +130,25 @@ def reset_matchms_logger(logger_name="matchms"):
     logger = logging.getLogger(logger_name)
     logger.handlers.clear()
     _init_logger()
+
+
+# function recreates the functionality of the rdkit function
+# https://github.com/rdkit/rdkit/blob/master/rdkit/RDLogger.py setLevel()
+def set_rdkit_logger_level(level):
+    # Rdkit log levels severity order
+    rdkit_log_levels = ['rdApp.debug', 'rdApp.info', 'rdApp.warning', 'rdApp.error']
+    if not _has_rdkit:
+        raise ImportError(rdkit_missing_message)
+
+    if level not in rdkit_log_levels:
+        raise ValueError(f"Invalid log level. Allowed values are: {rdkit_log_levels}")
+    # convert string level to index
+    level_index = rdkit_log_levels.index(level)
+
+    # enable all levels with higher severity
+    for i in range(level_index, len(rdkit_log_levels)):
+        RDLogger.EnableLog(rdkit_log_levels[i])
+
+    # disable all levels with lower severity
+    for i in range(0, level_index):
+        RDLogger.DisableLog(rdkit_log_levels[i])


Test patch:
diff --git a/tests/test_logging.py b/tests/test_logging.py
index 3c32a766..7d32fd9b 100644
--- a/tests/test_logging.py
+++ b/tests/test_logging.py
@@ -1,9 +1,11 @@
 # -*- coding: utf-8 -*-
 import logging
 import os
+import pytest
 from matchms.logging_functions import (add_logging_to_file,
                                        reset_matchms_logger,
-                                       set_matchms_logger_level)
+                                       set_matchms_logger_level,
+                                       set_rdkit_logger_level)
 
 
 def test_initial_logging(caplog, capsys):
@@ -86,3 +88,27 @@ def test_add_logging_to_file_only_file(tmp_path, capsys):
         logs = file.read()
     assert expected_log_entry in logs, "Expected different log file content"
     reset_matchms_logger()
+
+
+def test_set_rdkit_logger_level(capfd):
+    """Test if rdkit log level is set correctly."""
+    rdkit = pytest.importorskip("rdkit")
+    # create a dummy logger
+    logger = rdkit.RDLogger.logger()
+    rdkit_log_levels = ['rdApp.debug', 'rdApp.info', 'rdApp.warning', 'rdApp.error']
+
+    # test all log levels settings
+    for set_level, set_level_name in enumerate(rdkit_log_levels):
+        # set current log level, only logs with this level or higher severity should be printed
+        set_rdkit_logger_level(set_level_name)
+
+        # try to logg with all log levels
+        for logged_level, logged_level_name in enumerate(rdkit_log_levels):
+            logger.logIt(logged_level_name, "test")
+            captured = capfd.readouterr()
+            if set_level <= logged_level:
+                # if set log level severety is lower or equal to logged level, log should be printed
+                assert captured.out + captured.err != ""
+            else:
+                # if set log level severety is higher than logged level, log should not be printed
+                assert captured.out + captured.err == ""