ChemBioHTP / EnzyHTP

EnzyHTP is a python library that automates the complete life-cycle of enzyme modeling
https://enzyhtp-doc.readthedocs.io
Other
8 stars 1 forks source link

Solve the bug related to logging #126

Closed shaoqx closed 10 months ago

shaoqx commented 10 months ago

If PDB2PQR logging is redirected with a context manager, all logging after it will give this error

--- Logging error ---
Traceback (most recent call last):
  File "/home/shaoq1/bin/miniconda3/envs/uni_enzyhtp/lib/python3.9/logging/__init__.py", line 1086, in emit
    stream.write(msg + self.terminator)
ValueError: I/O operation on closed file.

This is pretty confusing since different loggers are used. Only the PDB2PQR related logger are configured under the redirected stderr context. EnzyHTP logger should not have the problem. It seems logging has handlers as global variables and the StreamHandler will cache the stderr when it is first initiated.

I found related discussion but none of them talks about cases with using different logger https://stackoverflow.com/questions/54999650/python3-redirected-stderr-not-reset-properly https://bugs.python.org/issue36193

shaoqx commented 10 months ago

This is an example code that reproduce the error

import logging
from wrapper import HiddenPrints

message = 'dummy test'

_LOGGER_1 = logging.getLogger("1")
handler_1 = logging.StreamHandler()
_LOGGER_1.addHandler(handler_1)

with HiddenPrints("test.log"):
    _LOGGER = logging.getLogger("")
    handler = logging.StreamHandler()
    _LOGGER.addHandler(handler)
    _LOGGER.warning(message)

_LOGGER_1.warning(message)

_LOGGER and _LOGGER_1 have completely different handlers

[<StreamHandler test.log (NOTSET)>]

and

[<StreamHandler <stderr> (NOTSET)>]

However, the error is still there.

shaoqx commented 10 months ago

In HiddenPrints it is just simply

class HiddenPrints:
    def __init__(self, redirect=os.devnull):
        self.redirect=redirect

    def __enter__(self):
        self._original_stdout = sys.stdout
        self._original_stderr = sys.stderr
        self.redirect_file_obj = open(self.redirect, 'w')
        sys.stdout = self.redirect_file_obj
        sys.stderr = self.redirect_file_obj

    def __exit__(self, exc_type, exc_val, exc_tb):
        self.redirect_file_obj.close()
        sys.stdout = self._original_stdout
        sys.stderr = self._original_stderr
shaoqx commented 10 months ago

Created an issue here https://github.com/python/cpython/issues/80374

shaoqx commented 10 months ago

Another fix (d32c80c81bc39e2e66cf9a442e80d7acb7e63fce) is also posted in old EnzyHTP related to this. This fix will migrate to the new EnzyHTP when it comes to it.

shaoqx commented 10 months ago

Note that PDB2PQR edited the root logger that will cause more root logger related problem in the future if we interface other packages that also use logging without propagate = False After a PDB2PQR run, here are handlers of the root logger: [<FileHandler /home/wkdir/pdb_file_name.log (NOTSET)>, <StreamHandler <stderr> (INFO)>]