From e1ebce4c7266fb9a44f4fb5046dd24dcdd1279f0 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Thu, 16 Oct 2025 13:39:08 -0700 Subject: [PATCH 01/15] do we test this at all? --- openfe/__init__.py | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/openfe/__init__.py b/openfe/__init__.py index a944cd8f2..3e5d91b2e 100644 --- a/openfe/__init__.py +++ b/openfe/__init__.py @@ -1,13 +1,13 @@ # silence pymbar logging warnings import logging -def _mute_timeseries(record): - return not "Warning on use of the timeseries module:" in record.msg -def _mute_jax(record): - return not "****** PyMBAR will use 64-bit JAX! *******" in record.msg -_mbar_log = logging.getLogger("pymbar.timeseries") -_mbar_log.addFilter(_mute_timeseries) -_mbar_log = logging.getLogger("pymbar.mbar_solvers") -_mbar_log.addFilter(_mute_jax) +#def _mute_timeseries(record): +# return not "Warning on use of the timeseries module:" in record.msg +#def _mute_jax(record): +# return not "****** PyMBAR will use 64-bit JAX! *******" in record.msg +#_mbar_log = logging.getLogger("pymbar.timeseries") +#_mbar_log.addFilter(_mute_timeseries) +#_mbar_log = logging.getLogger("pymbar.mbar_solvers") +#_mbar_log.addFilter(_mute_jax) from gufe import ( ChemicalSystem, From 866b969248c2b966e135d302f46fcd0294db3711 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Wed, 22 Oct 2025 14:10:08 -0700 Subject: [PATCH 02/15] start of logging improvements --- openfe/__init__.py | 3 ++- openfe/protocols/openmm_utils/multistate_analysis.py | 9 ++++++--- openfe/utils/logging_filter.py | 11 +++++++++-- 3 files changed, 17 insertions(+), 6 deletions(-) diff --git a/openfe/__init__.py b/openfe/__init__.py index 3e5d91b2e..85fa7c501 100644 --- a/openfe/__init__.py +++ b/openfe/__init__.py @@ -1,5 +1,7 @@ # silence pymbar logging warnings import logging + +from openfe.utils.logging_filter import MsgIncludesStringFilter #def _mute_timeseries(record): # return not "Warning on use of the timeseries module:" in record.msg #def _mute_jax(record): @@ -29,7 +31,6 @@ ProtocolResult, execute_DAG, ) - from . import utils from . import setup from .setup import ( diff --git a/openfe/protocols/openmm_utils/multistate_analysis.py b/openfe/protocols/openmm_utils/multistate_analysis.py index b8f486bba..cf740ac6f 100644 --- a/openfe/protocols/openmm_utils/multistate_analysis.py +++ b/openfe/protocols/openmm_utils/multistate_analysis.py @@ -11,8 +11,6 @@ from openmmtools import multistate from openff.units import unit, Quantity from openff.units.openmm import from_openmm -from pymbar import MBAR -from pymbar.utils import ParameterError from openfe.analysis import plotting from typing import Optional, Union from openfe.due import due, Doi @@ -227,8 +225,10 @@ def _get_free_energy( * Allow folks to pass in extra options for bootstrapping etc.. * Add standard test against analyzer.get_free_energy() """ + # pymbar has some side effects when imported so we only import it right when we + # need it + from pymbar import MBAR - # pymbar 4 mbar = MBAR( u_ln, N_l, @@ -310,6 +310,9 @@ def get_forward_and_reverse_analysis( issues with the solver when using low amounts of data points. All uncertainties are MBAR analytical errors. """ + # pymbar has some side effects from being imported, so we only want to import + # it right when we need it + from pymbar.utils import ParameterError try: u_ln = self.analyzer._unbiased_decorrelated_u_ln N_l = self.analyzer._unbiased_decorrelated_N_l diff --git a/openfe/utils/logging_filter.py b/openfe/utils/logging_filter.py index 78d00de57..cc51d1474 100644 --- a/openfe/utils/logging_filter.py +++ b/openfe/utils/logging_filter.py @@ -1,5 +1,3 @@ -import logging - class MsgIncludesStringFilter: """Logging filter to silence specfic log messages. @@ -16,3 +14,12 @@ def __init__(self, string): def filter(self, record): return not self.string in record.msg + + +class AppendMsgFilter: + """Logging filter to append a message to a specfic log message. + + See https://docs.python.org/3/library/logging.html#filter-objects + + """ + pass From 9cf7fee52adbe9aebe0cddbd3e79db59766a97cf Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Thu, 6 Nov 2025 16:57:32 -0700 Subject: [PATCH 03/15] first pass at logging, worried about performance --- openfe/__init__.py | 36 +++++--- openfe/utils/logging_control.py | 157 ++++++++++++++++++++++++++++++++ openfe/utils/logging_filter.py | 26 ------ 3 files changed, 181 insertions(+), 38 deletions(-) create mode 100644 openfe/utils/logging_control.py delete mode 100644 openfe/utils/logging_filter.py diff --git a/openfe/__init__.py b/openfe/__init__.py index 5661376db..1319a6416 100644 --- a/openfe/__init__.py +++ b/openfe/__init__.py @@ -1,15 +1,27 @@ -# silence pymbar logging warnings -import logging - -from openfe.utils.logging_filter import MsgIncludesStringFilter -#def _mute_timeseries(record): -# return not "Warning on use of the timeseries module:" in record.msg -#def _mute_jax(record): -# return not "****** PyMBAR will use 64-bit JAX! *******" in record.msg -#_mbar_log = logging.getLogger("pymbar.timeseries") -#_mbar_log.addFilter(_mute_timeseries) -#_mbar_log = logging.getLogger("pymbar.mbar_solvers") -#_mbar_log.addFilter(_mute_jax) +# We need to do this first so that we can set up our +# log control since some modules have warnings on import +from openfe.utils.logging_control import LogControl + + +LogControl.silence_message( + msg=["****** PyMBAR will use 64-bit JAX! *******",], + logger_names=["pymbar.mbar_solvers",] +) + +LogControl.silence_message( + msg=["Warning on use of the timeseries module:",], + logger_names=["pymbar.timeseries",] +) + +LogControl.append_logger( + suffix="see this url", + logger_names="jax._src.xla_bridge", + ) + + +from jax._src.xla_bridge import backends + +backends() from gufe import ( ChemicalSystem, diff --git a/openfe/utils/logging_control.py b/openfe/utils/logging_control.py new file mode 100644 index 000000000..56c0bc0b2 --- /dev/null +++ b/openfe/utils/logging_control.py @@ -0,0 +1,157 @@ +import logging + +class MsgIncludesStringFilter: + """Logging filter to silence specfic log messages. + + See https://docs.python.org/3/library/logging.html#filter-objects + + Parameters + ---------- + strings : str or list of str + If string(s) match in log messages (substring match) then the log record + is suppressed + """ + + def __init__(self, strings: str | list[str]) -> None: + if isinstance(strings, str): + strings = [strings] + self.strings = strings + + def filter(self, record: logging.LogRecord) -> bool: + """Filter log records that contain any of the specified strings. + + Parameters + ---------- + record : logging.LogRecord + Log record to filter + + Returns + ------- + bool + False if the record should be blocked, True if it should be logged + """ + for string in self.strings: + return not string in record.msg + + +class AppendMsgFilter: + """Logging filter to append a message to a specfic log message. + + See https://docs.python.org/3/library/logging.html#filter-objects + + """ + def __init__(self, suffix: str | list[str]) -> None: + if isinstance(suffix, str): + suffix = [suffix] + self.suffixes = suffix + + def filter(self, record: logging.LogRecord) -> bool: + """Append suffix to log record message. + + Parameters + ---------- + record : logging.LogRecord + Log record to modify + + Returns + ------- + bool + Always True to allow the record to be logged + """ + for suffix in self.suffixes: + # Only modify if not already appended (idempotent) + if not record.msg.endswith(suffix): + record.msg = f"{record.msg}{suffix}" + return True + + +class LogControl: + """Easy-to-use logging control for third-party packages.""" + + def __init__(self): + self._filters = [] + + @staticmethod + def silence_message(msg, logger_names): + """Silence specific log messages from one or more loggers. + + Parameters + ---------- + msg : str or list of str + String(s) to match in log messages (substring match) + logger_names : str or list of str + Logger name(s) to apply the filter to + + Examples + -------- + >>> LogControl.silence_message( + ... msg="****** PyMBAR will use 64-bit JAX! *******", + ... logger_names=["pymbar.timeseries", "pymbar.mbar_solvers"] + ... ) + >>> LogControl.silence_message( + ... msg=["warning 1", "warning 2", "warning 3"], + ... logger_names="some.package" + ... ) + """ + # Handle single string or list for both parameters + if isinstance(logger_names, str): + logger_names = [logger_names] + + if isinstance(msg, str): + msg = [msg] + + # Create a filter for each message + for message in msg: + filter_obj = MsgIncludesStringFilter(message) + for name in logger_names: + logging.getLogger(name).addFilter(filter_obj) + + @staticmethod + def silence_logger(logger_names, level=logging.CRITICAL): + """Completely silence one or more loggers. + + Parameters + ---------- + logger_names : str or list of str + Logger name(s) to silence + level : int + Set logger level (default: CRITICAL to silence everything) + + Examples + -------- + >>> LogControl.silence_logger(logger_names=["urllib3", "requests"]) + >>> LogControl.silence_logger(logger_names="noisy.package") + """ + if isinstance(logger_names, str): + logger_names = [logger_names] + + for name in logger_names: + logging.getLogger(name).setLevel(level) + + + @staticmethod + def append_logger(suffix: str | list[str], logger_names: str | list[str]): + """Add extra context to logger messages. + + Parameters + ---------- + logger_names : str or list of str + Logger name(s) to enhance + formatter : callable, optional + Function that takes a LogRecord and returns modified msg + extra_fields : dict, optional + Extra fields to add to LogRecord + + Examples + -------- + >>> LogControl.append_logger( + ... logger_names="myapp", + ... extra_fields={'version': '1.0', 'env': 'prod'} + ... ) + """ + if isinstance(logger_names, str): + logger_names = [logger_names] + + filter_obj = AppendMsgFilter(suffix) + for name in logger_names: + logging.getLogger(name).addFilter(filter_obj) diff --git a/openfe/utils/logging_filter.py b/openfe/utils/logging_filter.py deleted file mode 100644 index 5a89cfa66..000000000 --- a/openfe/utils/logging_filter.py +++ /dev/null @@ -1,26 +0,0 @@ -class MsgIncludesStringFilter: - """Logging filter to silence specfic log messages. - - See https://docs.python.org/3/library/logging.html#filter-objects - - Parameters - ---------- - string : str - if an exact for this is included in the log message, the log record - is suppressed - """ - - def __init__(self, string): - self.string = string - - def filter(self, record): - return not self.string in record.msg - - -class AppendMsgFilter: - """Logging filter to append a message to a specfic log message. - - See https://docs.python.org/3/library/logging.html#filter-objects - - """ - pass From 906ff5ed29a151d1fbad8fd006a6944180bff1a5 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Fri, 7 Nov 2025 09:32:09 -0700 Subject: [PATCH 04/15] setup a base class + add type hints --- openfe/utils/logging_control.py | 103 +++++++++++++++++++------------- 1 file changed, 62 insertions(+), 41 deletions(-) diff --git a/openfe/utils/logging_control.py b/openfe/utils/logging_control.py index 56c0bc0b2..988b93f4e 100644 --- a/openfe/utils/logging_control.py +++ b/openfe/utils/logging_control.py @@ -1,21 +1,49 @@ import logging +from abc import ABC, abstractmethod -class MsgIncludesStringFilter: - """Logging filter to silence specfic log messages. - See https://docs.python.org/3/library/logging.html#filter-objects +class BaseLogFilter(ABC): + """Base class for log filters that handle string or list of strings. Parameters ---------- strings : str or list of str - If string(s) match in log messages (substring match) then the log record - is suppressed + String(s) to use in the filter logic """ def __init__(self, strings: str | list[str]) -> None: if isinstance(strings, str): strings = [strings] - self.strings = strings + self.strings: list[str] = strings + + @abstractmethod + def filter(self, record: logging.LogRecord) -> bool: + """Filter method to be implemented by subclasses. + + Parameters + ---------- + record : logging.LogRecord + Log record to filter/modify + + Returns + ------- + bool + True to allow the record, False to block it + """ + pass + + +class MsgIncludesStringFilter(BaseLogFilter): + """Logging filter to silence specific log messages. + + See https://docs.python.org/3/library/logging.html#filter-objects + + Parameters + ---------- + strings : str or list of str + If string(s) match in log messages (substring match) then the log record + is suppressed + """ def filter(self, record: logging.LogRecord) -> bool: """Filter log records that contain any of the specified strings. @@ -31,19 +59,26 @@ def filter(self, record: logging.LogRecord) -> bool: False if the record should be blocked, True if it should be logged """ for string in self.strings: - return not string in record.msg + if string in record.msg: + return False + return True -class AppendMsgFilter: - """Logging filter to append a message to a specfic log message. +class AppendMsgFilter(BaseLogFilter): + """Logging filter to append a message to a specific log message. See https://docs.python.org/3/library/logging.html#filter-objects + Parameters + ---------- + strings : str or list of str + Suffix text(s) to append to log messages """ - def __init__(self, suffix: str | list[str]) -> None: - if isinstance(suffix, str): - suffix = [suffix] - self.suffixes = suffix + + def __init__(self, strings: str | list[str]) -> None: + super().__init__(strings) + # Rename for clarity in this context + self.suffixes = self.strings def filter(self, record: logging.LogRecord) -> bool: """Append suffix to log record message. @@ -68,11 +103,11 @@ def filter(self, record: logging.LogRecord) -> bool: class LogControl: """Easy-to-use logging control for third-party packages.""" - def __init__(self): - self._filters = [] + def __init__(self) -> None: + self._filters: list = [] @staticmethod - def silence_message(msg, logger_names): + def silence_message(msg: str | list[str], logger_names: str | list[str]) -> None: """Silence specific log messages from one or more loggers. Parameters @@ -88,26 +123,16 @@ def silence_message(msg, logger_names): ... msg="****** PyMBAR will use 64-bit JAX! *******", ... logger_names=["pymbar.timeseries", "pymbar.mbar_solvers"] ... ) - >>> LogControl.silence_message( - ... msg=["warning 1", "warning 2", "warning 3"], - ... logger_names="some.package" - ... ) """ - # Handle single string or list for both parameters if isinstance(logger_names, str): logger_names = [logger_names] - if isinstance(msg, str): - msg = [msg] - - # Create a filter for each message - for message in msg: - filter_obj = MsgIncludesStringFilter(message) - for name in logger_names: - logging.getLogger(name).addFilter(filter_obj) + filter_obj = MsgIncludesStringFilter(msg) + for name in logger_names: + logging.getLogger(name).addFilter(filter_obj) @staticmethod - def silence_logger(logger_names, level=logging.CRITICAL): + def silence_logger(logger_names: str | list[str], level: int = logging.CRITICAL) -> None: """Completely silence one or more loggers. Parameters @@ -120,7 +145,6 @@ def silence_logger(logger_names, level=logging.CRITICAL): Examples -------- >>> LogControl.silence_logger(logger_names=["urllib3", "requests"]) - >>> LogControl.silence_logger(logger_names="noisy.package") """ if isinstance(logger_names, str): logger_names = [logger_names] @@ -128,25 +152,22 @@ def silence_logger(logger_names, level=logging.CRITICAL): for name in logger_names: logging.getLogger(name).setLevel(level) - @staticmethod - def append_logger(suffix: str | list[str], logger_names: str | list[str]): - """Add extra context to logger messages. + def append_logger(suffix: str | list[str], logger_names: str | list[str]) -> None: + """Append text to logger messages. Parameters ---------- + suffix : str or list of str + Suffix text to append to log messages logger_names : str or list of str - Logger name(s) to enhance - formatter : callable, optional - Function that takes a LogRecord and returns modified msg - extra_fields : dict, optional - Extra fields to add to LogRecord + Logger name(s) to modify Examples -------- >>> LogControl.append_logger( - ... logger_names="myapp", - ... extra_fields={'version': '1.0', 'env': 'prod'} + ... suffix=" [DEPRECATED]", + ... logger_names="myapp" ... ) """ if isinstance(logger_names, str): From 04c4b721e459aebb9f17f9f8311a2828cb037b22 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Fri, 7 Nov 2025 09:35:50 -0700 Subject: [PATCH 05/15] add placeholder url ref --- openfe/__init__.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/openfe/__init__.py b/openfe/__init__.py index 1319a6416..16c4ec630 100644 --- a/openfe/__init__.py +++ b/openfe/__init__.py @@ -14,13 +14,13 @@ ) LogControl.append_logger( - suffix="see this url", + suffix="\n \n[OPENFE]: See this url for more information about the warning above\n", logger_names="jax._src.xla_bridge", ) - +# These two lines are just to test the append_logger and will be removed before +# the PR is merged from jax._src.xla_bridge import backends - backends() from gufe import ( From 964d10f96efb71a7f000ce5669ee053898ceb5cd Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Fri, 7 Nov 2025 16:37:57 +0000 Subject: [PATCH 06/15] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- openfe/__init__.py | 23 +++++++++++++------ .../openmm_utils/multistate_analysis.py | 1 + 2 files changed, 17 insertions(+), 7 deletions(-) diff --git a/openfe/__init__.py b/openfe/__init__.py index 16c4ec630..5fa632420 100644 --- a/openfe/__init__.py +++ b/openfe/__init__.py @@ -4,23 +4,32 @@ LogControl.silence_message( - msg=["****** PyMBAR will use 64-bit JAX! *******",], - logger_names=["pymbar.mbar_solvers",] + msg=[ + "****** PyMBAR will use 64-bit JAX! *******", + ], + logger_names=[ + "pymbar.mbar_solvers", + ], ) LogControl.silence_message( - msg=["Warning on use of the timeseries module:",], - logger_names=["pymbar.timeseries",] + msg=[ + "Warning on use of the timeseries module:", + ], + logger_names=[ + "pymbar.timeseries", + ], ) LogControl.append_logger( - suffix="\n \n[OPENFE]: See this url for more information about the warning above\n", - logger_names="jax._src.xla_bridge", - ) + suffix="\n \n[OPENFE]: See this url for more information about the warning above\n", + logger_names="jax._src.xla_bridge", +) # These two lines are just to test the append_logger and will be removed before # the PR is merged from jax._src.xla_bridge import backends + backends() from gufe import ( diff --git a/openfe/protocols/openmm_utils/multistate_analysis.py b/openfe/protocols/openmm_utils/multistate_analysis.py index 967819ace..9fe32f500 100644 --- a/openfe/protocols/openmm_utils/multistate_analysis.py +++ b/openfe/protocols/openmm_utils/multistate_analysis.py @@ -314,6 +314,7 @@ def get_forward_and_reverse_analysis( # pymbar has some side effects from being imported, so we only want to import # it right when we need it from pymbar.utils import ParameterError + try: u_ln = self.analyzer._unbiased_decorrelated_u_ln N_l = self.analyzer._unbiased_decorrelated_N_l From 7e87d4cdca33d9d3385d6df4c1a31990f3149e0b Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Fri, 7 Nov 2025 10:39:08 -0700 Subject: [PATCH 07/15] update to new logging control --- openfecli/commands/quickrun.py | 20 ++++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/openfecli/commands/quickrun.py b/openfecli/commands/quickrun.py index 8e24a9ead..8721ff1e9 100644 --- a/openfecli/commands/quickrun.py +++ b/openfecli/commands/quickrun.py @@ -6,7 +6,7 @@ import pathlib from openfecli import OFECommandPlugin -from openfecli.utils import write, print_duration, configure_logger +from openfecli.utils import write, print_duration, LogControl, configure_logger def _format_exception(exception) -> str: @@ -52,7 +52,6 @@ def quickrun(transformation, work_dir, output): from gufe.transformations.transformation import Transformation from gufe.protocols.protocoldag import execute_DAG from gufe.tokenization import JSON_HANDLER - from openfe.utils.logging_filter import MsgIncludesStringFilter import logging # avoid problems with output not showing if queueing system kills a job @@ -65,15 +64,16 @@ def quickrun(transformation, work_dir, output): configure_logger("openfe", handler=stdout_handler) # silence the openmmtools.multistate API warning - stfu = MsgIncludesStringFilter( - "The openmmtools.multistate API is experimental and may change in future releases" + LogControl.silence_message( + msg=[ + "The openmmtools.multistate API is experimental and may change in future releases", + ], + logger_names=[ + "openmmtools.multistate.multistatereporter", + "openmmtools.multistate.multistateanalyzer", + "openmmtools.multistate.multistatesampler", + ], ) - omm_multistate = "openmmtools.multistate" - modules = ["multistatereporter", "multistateanalyzer", "multistatesampler"] - for module in modules: - ms_log = logging.getLogger(omm_multistate + "." + module) - ms_log.addFilter(stfu) - # turn warnings into log message (don't show stack trace) logging.captureWarnings(True) From 82badf2e067ee25b32f74d28c105692e94bdbcd6 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Fri, 7 Nov 2025 10:54:02 -0700 Subject: [PATCH 08/15] Fix imports --- openfe/utils/__init__.py | 1 + openfecli/commands/quickrun.py | 3 ++- 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/openfe/utils/__init__.py b/openfe/utils/__init__.py index 0d276a97e..ee8c2e2bd 100644 --- a/openfe/utils/__init__.py +++ b/openfe/utils/__init__.py @@ -5,3 +5,4 @@ from .optional_imports import requires_package from .remove_oechem import without_oechem_backend from .system_probe import log_system_probe +from .logging_control import LogControl diff --git a/openfecli/commands/quickrun.py b/openfecli/commands/quickrun.py index 8721ff1e9..c3f0ada39 100644 --- a/openfecli/commands/quickrun.py +++ b/openfecli/commands/quickrun.py @@ -6,7 +6,7 @@ import pathlib from openfecli import OFECommandPlugin -from openfecli.utils import write, print_duration, LogControl, configure_logger +from openfecli.utils import write, print_duration, configure_logger def _format_exception(exception) -> str: @@ -49,6 +49,7 @@ def quickrun(transformation, work_dir, output): """ import os import sys + from openfe.utils import LogControl from gufe.transformations.transformation import Transformation from gufe.protocols.protocoldag import execute_DAG from gufe.tokenization import JSON_HANDLER From 87645aa935be0bf978e4e3c2a083c0b9ac936b03 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Fri, 7 Nov 2025 10:55:05 -0700 Subject: [PATCH 09/15] remove bit left over from being able to delete these log controlers --- openfe/utils/logging_control.py | 2 -- 1 file changed, 2 deletions(-) diff --git a/openfe/utils/logging_control.py b/openfe/utils/logging_control.py index 988b93f4e..b05dfde89 100644 --- a/openfe/utils/logging_control.py +++ b/openfe/utils/logging_control.py @@ -103,8 +103,6 @@ def filter(self, record: logging.LogRecord) -> bool: class LogControl: """Easy-to-use logging control for third-party packages.""" - def __init__(self) -> None: - self._filters: list = [] @staticmethod def silence_message(msg: str | list[str], logger_names: str | list[str]) -> None: From 3bab24dd57bc873870005a9b6513b1ceb31d41a8 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Fri, 7 Nov 2025 10:55:27 -0700 Subject: [PATCH 10/15] looks like ... is used more than pass --- openfe/utils/logging_control.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/openfe/utils/logging_control.py b/openfe/utils/logging_control.py index b05dfde89..fe439ceda 100644 --- a/openfe/utils/logging_control.py +++ b/openfe/utils/logging_control.py @@ -30,7 +30,7 @@ def filter(self, record: logging.LogRecord) -> bool: bool True to allow the record, False to block it """ - pass + ... class MsgIncludesStringFilter(BaseLogFilter): From d01b937da2dc335dd204183e9fdc1a92c0ab5ee6 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Mon, 10 Nov 2025 16:17:00 -0700 Subject: [PATCH 11/15] formatting fix --- openfe/utils/logging_control.py | 1 - 1 file changed, 1 deletion(-) diff --git a/openfe/utils/logging_control.py b/openfe/utils/logging_control.py index fe439ceda..051427e76 100644 --- a/openfe/utils/logging_control.py +++ b/openfe/utils/logging_control.py @@ -103,7 +103,6 @@ def filter(self, record: logging.LogRecord) -> bool: class LogControl: """Easy-to-use logging control for third-party packages.""" - @staticmethod def silence_message(msg: str | list[str], logger_names: str | list[str]) -> None: """Silence specific log messages from one or more loggers. From cb495e80694659e51cd56e39dd93bf12ff6e6f94 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Mon, 10 Nov 2025 16:24:39 -0700 Subject: [PATCH 12/15] Grab new format rule from main --- pyproject.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pyproject.toml b/pyproject.toml index 7cc5f139f..e5a18bb3b 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -53,7 +53,7 @@ line-length = 100 # Enable Pyflakes (`F`) and a subset of the pycodestyle (`E`) codes by default. lint.select = [ # "F", # Pyflakes - # "I", # isort + "I", # isort # "W", # pycodestyle warnings # "E", # pycodestyle errors # "C901" # mccabe complexity TODO: add this back in From 93aecdddc9f29e15a09ad354a0768f299597280a Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Mon, 10 Nov 2025 16:32:20 -0700 Subject: [PATCH 13/15] run ruff check --fix on conflicting files --- openfe/__init__.py | 31 +++++++++---------- .../openmm_utils/multistate_analysis.py | 13 ++++---- openfecli/commands/quickrun.py | 13 +++++--- 3 files changed, 29 insertions(+), 28 deletions(-) diff --git a/openfe/__init__.py b/openfe/__init__.py index 5fa632420..6c860e7f5 100644 --- a/openfe/__init__.py +++ b/openfe/__init__.py @@ -2,7 +2,6 @@ # log control since some modules have warnings on import from openfe.utils.logging_control import LogControl - LogControl.silence_message( msg=[ "****** PyMBAR will use 64-bit JAX! *******", @@ -32,41 +31,39 @@ backends() +from importlib.metadata import version + from gufe import ( + AlchemicalNetwork, ChemicalSystem, Component, + LigandAtomMapping, + NonTransformation, ProteinComponent, SmallMoleculeComponent, SolventComponent, Transformation, - NonTransformation, - AlchemicalNetwork, - LigandAtomMapping, ) from gufe.protocols import ( Protocol, ProtocolDAG, - ProtocolUnit, - ProtocolUnitResult, - ProtocolUnitFailure, ProtocolDAGResult, ProtocolResult, + ProtocolUnit, + ProtocolUnitFailure, + ProtocolUnitResult, execute_DAG, ) -from . import utils -from . import setup + +from . import analysis, orchestration, setup, utils from .setup import ( + LigandAtomMapper, + LigandNetwork, LomapAtomMapper, - lomap_scorers, PersesAtomMapper, - perses_scorers, ligand_network_planning, - LigandNetwork, - LigandAtomMapper, + lomap_scorers, + perses_scorers, ) -from . import orchestration -from . import analysis - -from importlib.metadata import version __version__ = version("openfe") diff --git a/openfe/protocols/openmm_utils/multistate_analysis.py b/openfe/protocols/openmm_utils/multistate_analysis.py index 9fe32f500..6f1d785d2 100644 --- a/openfe/protocols/openmm_utils/multistate_analysis.py +++ b/openfe/protocols/openmm_utils/multistate_analysis.py @@ -4,18 +4,19 @@ Reusable utility methods to analyze results from multistate calculations. """ -from pathlib import Path import warnings +from pathlib import Path +from typing import Optional, Union + import matplotlib.pyplot as plt import numpy as np import numpy.typing as npt -from openmmtools import multistate -from openff.units import unit, Quantity +from openff.units import Quantity, unit from openff.units.openmm import from_openmm -from openfe.analysis import plotting -from typing import Optional, Union -from openfe.due import due, Doi +from openmmtools import multistate +from openfe.analysis import plotting +from openfe.due import Doi, due due.cite( Doi("10.5281/zenodo.596622"), diff --git a/openfecli/commands/quickrun.py b/openfecli/commands/quickrun.py index c3f0ada39..73becd792 100644 --- a/openfecli/commands/quickrun.py +++ b/openfecli/commands/quickrun.py @@ -1,12 +1,13 @@ # This code is part of OpenFE and is licensed under the MIT license. # For details, see https://github.com/OpenFreeEnergy/openfe -import click import json import pathlib +import click + from openfecli import OFECommandPlugin -from openfecli.utils import write, print_duration, configure_logger +from openfecli.utils import configure_logger, print_duration, write def _format_exception(exception) -> str: @@ -47,13 +48,15 @@ def quickrun(transformation, work_dir, output): For example, when running the OpenMM HREX Protocol a directory will be created for each repeat of the sampling process (by default 3). """ + import logging import os import sys - from openfe.utils import LogControl - from gufe.transformations.transformation import Transformation + from gufe.protocols.protocoldag import execute_DAG from gufe.tokenization import JSON_HANDLER - import logging + from gufe.transformations.transformation import Transformation + + from openfe.utils import LogControl # avoid problems with output not showing if queueing system kills a job sys.stdout.reconfigure(line_buffering=True) From ff14c7d1f37054af5da87d0eade4191236f26a8b Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Mon, 10 Nov 2025 23:49:34 +0000 Subject: [PATCH 14/15] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- openfe/__init__.py | 2 -- openfe/utils/__init__.py | 2 +- 2 files changed, 1 insertion(+), 3 deletions(-) diff --git a/openfe/__init__.py b/openfe/__init__.py index 64abd3ac6..6c860e7f5 100644 --- a/openfe/__init__.py +++ b/openfe/__init__.py @@ -33,8 +33,6 @@ from importlib.metadata import version -from importlib.metadata import version - from gufe import ( AlchemicalNetwork, ChemicalSystem, diff --git a/openfe/utils/__init__.py b/openfe/utils/__init__.py index ee8c2e2bd..ae894c66b 100644 --- a/openfe/utils/__init__.py +++ b/openfe/utils/__init__.py @@ -2,7 +2,7 @@ # For details, see https://github.com/OpenFreeEnergy/openfe from . import custom_typing +from .logging_control import LogControl from .optional_imports import requires_package from .remove_oechem import without_oechem_backend from .system_probe import log_system_probe -from .logging_control import LogControl From 0b3319c3093075db0f789f7fea786e42f6d00a17 Mon Sep 17 00:00:00 2001 From: Mike Henry <11765982+mikemhenry@users.noreply.github.com> Date: Mon, 17 Nov 2025 16:00:50 -0700 Subject: [PATCH 15/15] Added tests --- openfe/tests/utils/test_log_control.py | 512 +++++++++++++++++++++++++ 1 file changed, 512 insertions(+) create mode 100644 openfe/tests/utils/test_log_control.py diff --git a/openfe/tests/utils/test_log_control.py b/openfe/tests/utils/test_log_control.py new file mode 100644 index 000000000..6e79ad3e3 --- /dev/null +++ b/openfe/tests/utils/test_log_control.py @@ -0,0 +1,512 @@ +import logging + +import pytest + +from openfe.utils.logging_control import ( + AppendMsgFilter, + BaseLogFilter, + LogControl, + MsgIncludesStringFilter, +) + + +@pytest.fixture +def logger(): + """Create a test logger with a handler that captures log records.""" + test_logger = logging.getLogger("test_logger") + test_logger.setLevel(logging.DEBUG) + test_logger.handlers = [] # Clear any existing handlers + + # Create a handler that stores log records + class ListHandler(logging.Handler): + def __init__(self): + super().__init__() + self.records = [] + + def emit(self, record): + self.records.append(record) + + handler = ListHandler() + test_logger.addHandler(handler) + + yield test_logger, handler + + # Cleanup + test_logger.handlers = [] + test_logger.filters = [] + + +class TestMsgIncludesStringFilter: + """Tests for MsgIncludesStringFilter.""" + + def test_single_string_blocks_matching_message(self): + """Test that a single string blocks messages containing it.""" + filter_obj = MsgIncludesStringFilter("block this") + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="Please block this message", + args=(), + exc_info=None, + ) + assert filter_obj.filter(record) is False + + def test_single_string_allows_non_matching_message(self): + """Test that messages not containing the string are allowed.""" + filter_obj = MsgIncludesStringFilter("block this") + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="This is fine", + args=(), + exc_info=None, + ) + assert filter_obj.filter(record) is True + + def test_list_of_strings_blocks_any_match(self): + """Test that any string in the list blocks the message.""" + filter_obj = MsgIncludesStringFilter(["warning1", "warning2", "warning3"]) + + record1 = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="This has warning1 in it", + args=(), + exc_info=None, + ) + assert filter_obj.filter(record1) is False + + record2 = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="This has warning3 in it", + args=(), + exc_info=None, + ) + assert filter_obj.filter(record2) is False + + def test_list_allows_non_matching_messages(self): + """Test that messages not matching any string are allowed.""" + filter_obj = MsgIncludesStringFilter(["warning1", "warning2"]) + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="This is completely different", + args=(), + exc_info=None, + ) + assert filter_obj.filter(record) is True + + def test_substring_matching(self): + """Test that substring matching works correctly.""" + filter_obj = MsgIncludesStringFilter("JAX") + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="****** PyMBAR will use 64-bit JAX! *******", + args=(), + exc_info=None, + ) + assert filter_obj.filter(record) is False + + def test_case_sensitive_matching(self): + """Test that matching is case-sensitive.""" + filter_obj = MsgIncludesStringFilter("Error") + + record1 = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="This has Error in it", + args=(), + exc_info=None, + ) + assert filter_obj.filter(record1) is False + + record2 = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="This has error in it", + args=(), + exc_info=None, + ) + assert filter_obj.filter(record2) is True + + +class TestAppendMsgFilter: + """Tests for AppendMsgFilter.""" + + def test_single_suffix_appends(self): + """Test that a single suffix is appended to the message.""" + filter_obj = AppendMsgFilter(" [DEPRECATED]") + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="Original message", + args=(), + exc_info=None, + ) + result = filter_obj.filter(record) + assert result is True + assert record.msg == "Original message [DEPRECATED]" + + def test_multiple_suffixes_append_in_order(self): + """Test that multiple suffixes are appended in order.""" + filter_obj = AppendMsgFilter([" [DEPRECATED]", " - see docs"]) + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="Original message", + args=(), + exc_info=None, + ) + filter_obj.filter(record) + assert record.msg == "Original message [DEPRECATED] - see docs" + + def test_idempotent_single_suffix(self): + """Test that applying the same suffix twice is idempotent.""" + filter_obj = AppendMsgFilter(" [DEPRECATED]") + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="Original message [DEPRECATED]", + args=(), + exc_info=None, + ) + filter_obj.filter(record) + assert record.msg == "Original message [DEPRECATED]" + + def test_idempotent_multiple_suffixes(self): + """Test idempotency with multiple suffixes.""" + filter_obj = AppendMsgFilter([" [DEPRECATED] - see docs", " [DEPRECATED] - see docs"]) + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="Original message [DEPRECATED] - see docs", + args=(), + exc_info=None, + ) + filter_obj.filter(record) + assert record.msg == "Original message [DEPRECATED] - see docs" + + def test_always_returns_true(self): + """Test that the filter always returns True to allow logging.""" + filter_obj = AppendMsgFilter(" [INFO]") + record = logging.LogRecord( + name="test", + level=logging.INFO, + pathname="", + lineno=0, + msg="Message", + args=(), + exc_info=None, + ) + assert filter_obj.filter(record) is True + + +class TestLogControl: + """Tests for LogControl class.""" + + def test_silence_message_single_string_single_logger(self, logger): + """Test silencing a single message from a single logger.""" + test_logger, handler = logger + + LogControl.silence_message(msg="block this", logger_names="test_logger") + + test_logger.info("block this message") + test_logger.info("allow this message") + + assert len(handler.records) == 1 + assert handler.records[0].msg == "allow this message" + + def test_silence_message_multiple_strings_single_logger(self, logger): + """Test silencing multiple messages from a single logger.""" + test_logger, handler = logger + + LogControl.silence_message(msg=["warning1", "warning2"], logger_names="test_logger") + + test_logger.info("This has warning1") + test_logger.info("This has warning2") + test_logger.info("This is fine") + + assert len(handler.records) == 1 + assert handler.records[0].msg == "This is fine" + + def test_silence_message_single_string_multiple_loggers(self): + """Test silencing a message from multiple loggers.""" + logger1 = logging.getLogger("test_logger1") + logger2 = logging.getLogger("test_logger2") + + # Clear any existing filters + logger1.filters = [] + logger2.filters = [] + + LogControl.silence_message(msg="block this", logger_names=["test_logger1", "test_logger2"]) + + assert len(logger1.filters) == 1 + assert len(logger2.filters) == 1 + + # Cleanup + logger1.filters = [] + logger2.filters = [] + + def test_silence_message_multiple_strings_multiple_loggers(self): + """Test silencing multiple messages from multiple loggers.""" + logger1 = logging.getLogger("test_logger1") + logger2 = logging.getLogger("test_logger2") + + logger1.filters = [] + logger2.filters = [] + + LogControl.silence_message( + msg=["warning1", "warning2"], logger_names=["test_logger1", "test_logger2"] + ) + + # Should have one filter per logger (not one per message) + assert len(logger1.filters) == 1 + assert len(logger2.filters) == 1 + + # Cleanup + logger1.filters = [] + logger2.filters = [] + + def test_silence_logger_single(self, logger): + """Test completely silencing a single logger.""" + test_logger, handler = logger + + LogControl.silence_logger(logger_names="test_logger") + + test_logger.debug("debug message") + test_logger.info("info message") + test_logger.warning("warning message") + test_logger.error("error message") + + # All messages should be blocked + assert len(handler.records) == 0 + + def test_silence_logger_multiple(self): + """Test silencing multiple loggers.""" + logger1 = logging.getLogger("test_logger1") + logger2 = logging.getLogger("test_logger2") + + original_level1 = logger1.level + original_level2 = logger2.level + + LogControl.silence_logger(logger_names=["test_logger1", "test_logger2"]) + + assert logger1.level == logging.CRITICAL + assert logger2.level == logging.CRITICAL + + # Cleanup + logger1.setLevel(original_level1) + logger2.setLevel(original_level2) + + def test_silence_logger_custom_level(self, logger): + """Test silencing logger with custom level.""" + test_logger, handler = logger + + LogControl.silence_logger(logger_names="test_logger", level=logging.ERROR) + + test_logger.debug("debug message") + test_logger.info("info message") + test_logger.warning("warning message") + test_logger.error("error message") + + # Only error and above should pass through + assert len(handler.records) == 1 + assert handler.records[0].msg == "error message" + + def test_append_logger_single_suffix_single_logger(self, logger): + """Test appending a single suffix to a single logger.""" + test_logger, handler = logger + + LogControl.append_logger(suffix=" [DEPRECATED]", logger_names="test_logger") + + test_logger.info("Original message") + + assert len(handler.records) == 1 + assert handler.records[0].msg == "Original message [DEPRECATED]" + + def test_append_logger_multiple_suffixes(self, logger): + """Test appending multiple suffixes.""" + test_logger, handler = logger + + LogControl.append_logger( + suffix=[" [DEPRECATED]", " - see docs"], logger_names="test_logger" + ) + + test_logger.info("Original message") + + assert len(handler.records) == 1 + assert handler.records[0].msg == "Original message [DEPRECATED] - see docs" + + def test_append_logger_multiple_loggers(self): + """Test appending to multiple loggers.""" + logger1 = logging.getLogger("test_logger1") + logger2 = logging.getLogger("test_logger2") + + logger1.filters = [] + logger2.filters = [] + + LogControl.append_logger(suffix=" [INFO]", logger_names=["test_logger1", "test_logger2"]) + + assert len(logger1.filters) == 1 + assert len(logger2.filters) == 1 + + # Cleanup + logger1.filters = [] + logger2.filters = [] + + def test_pymbar_example(self, logger): + """Test the PyMBAR use case.""" + test_logger, handler = logger + + LogControl.silence_message( + msg="****** PyMBAR will use 64-bit JAX! *******", logger_names="test_logger" + ) + + test_logger.info("****** PyMBAR will use 64-bit JAX! *******") + test_logger.info("Other message") + + assert len(handler.records) == 1 + assert handler.records[0].msg == "Other message" + + def test_combining_multiple_controls(self, logger): + """Test combining silence and append on the same logger.""" + test_logger, handler = logger + + LogControl.silence_message(msg="block", logger_names="test_logger") + LogControl.append_logger(suffix=" [INFO]", logger_names="test_logger") + + test_logger.info("block this") + test_logger.info("allow this") + + assert len(handler.records) == 1 + assert handler.records[0].msg == "allow this [INFO]" + + +class TestBaseLogFilter: + """Tests for BaseLogFilter base class.""" + + def test_cannot_instantiate_abstract_class(self): + """Test that BaseLogFilter cannot be instantiated directly.""" + with pytest.raises(TypeError): + BaseLogFilter("test") + + def test_subclass_must_implement_filter(self): + """Test that subclasses must implement the filter method.""" + + class IncompleteFilter(BaseLogFilter): + pass + + with pytest.raises(TypeError): + IncompleteFilter("test") + + def test_subclass_with_filter_works(self): + """Test that a proper subclass can be instantiated.""" + + class CompleteFilter(BaseLogFilter): + def filter(self, record): + return True + + filter_obj = CompleteFilter("test") + assert filter_obj.strings == ["test"] + + def test_string_conversion_to_list(self): + """Test that single strings are converted to lists.""" + filter_obj = MsgIncludesStringFilter("single") + assert isinstance(filter_obj.strings, list) + assert filter_obj.strings == ["single"] + + def test_list_stays_as_list(self): + """Test that lists remain as lists.""" + filter_obj = MsgIncludesStringFilter(["one", "two", "three"]) + assert isinstance(filter_obj.strings, list) + assert filter_obj.strings == ["one", "two", "three"] + + +class TestEdgeCases: + """Tests for edge cases and error conditions.""" + + def test_empty_string(self, logger): + """Test behavior with empty string.""" + test_logger, handler = logger + + LogControl.silence_message(msg="", logger_names="test_logger") + + test_logger.info("message") + + # Empty string matches everything as substring + assert len(handler.records) == 0 + + def test_empty_list(self, logger): + """Test behavior with empty list.""" + test_logger, handler = logger + + LogControl.silence_message(msg=[], logger_names="test_logger") + + test_logger.info("message") + + # Empty list should not block anything + assert len(handler.records) == 1 + + def test_special_characters_in_message(self, logger): + """Test that special characters are handled correctly.""" + test_logger, handler = logger + + LogControl.silence_message(msg="[WARNING] *special* $chars$", logger_names="test_logger") + + test_logger.info("[WARNING] *special* $chars$ in message") + test_logger.info("normal message") + + assert len(handler.records) == 1 + assert handler.records[0].msg == "normal message" + + def test_unicode_characters(self, logger): + """Test that unicode characters work correctly.""" + test_logger, handler = logger + + LogControl.silence_message(msg="🚫 blocked", logger_names="test_logger") + LogControl.append_logger(suffix=" ✅", logger_names="test_logger") + + test_logger.info("🚫 blocked message") + test_logger.info("allowed message") + + assert len(handler.records) == 1 + assert handler.records[0].msg == "allowed message ✅" + + def test_very_long_message(self, logger): + """Test handling of very long messages.""" + test_logger, handler = logger + + long_msg = "x" * 10000 + LogControl.silence_message(msg="needle", logger_names="test_logger") + + test_logger.info(long_msg + "needle" + long_msg) + test_logger.info("short message") + + assert len(handler.records) == 1 + assert handler.records[0].msg == "short message"