dm_control icon indicating copy to clipboard operation
dm_control copied to clipboard

Python logging altered on import

Open surgura opened this issue 3 years ago • 5 comments

Importing dm_control modifies the standard python logging module. As far as I can tell this is done using Google's abseil. Abseil itself already moved away from this behaviour: https://github.com/abseil/abseil-py/issues/99. Can we do this too for dm_control?

surgura avatar Jun 30 '22 10:06 surgura

What version of absl-py do you have installed?

dm_control requires 0.7.0 or later, but this fix was included in 0.8.0. Do you still see the issue if you manually pip install the latest absl-py?

nimrod-gileadi avatar Jul 01 '22 13:07 nimrod-gileadi

I am running absl 1.1.0.

Currently I am importing mujoco as follows to prevent this issue:

    import logging

    old_len = len(logging.root.handlers)

    from dm_control import mjcf

    new_len = len(logging.root.handlers)

    assert (
        old_len + 1 == new_len
    ), "dm_control not adding logging handler as expected."

    logging.root.removeHandler(logging.root.handlers[-1])

Doing this or not importing mjcf at all solves the issue, so it must be somewhere in there. Thank you for your response.

surgura avatar Jul 01 '22 14:07 surgura

I'm seeing the following behaviour from the standard logging library

>>> import logging
>>> len(logging.root.handlers)
0
>>> logging.info("banana")
>>> len(logging.root.handlers)
1

so I don't think you're looking at the right thing. Did you see any other evidence of absl logging handlers being installed?

In the example you posted, the new logging handler is a <StreamHandler <stderr> (NOTSET)>, which is the same thing I get if I just call logging.info myself.

nimrod-gileadi avatar Jul 01 '22 14:07 nimrod-gileadi

Sorry I should have provided a minimal example. See below:

import logging
from dm_control import mjcf

logging.basicConfig(
    level=logging.INFO,
    format="[%(asctime)s] [%(levelname)s] [%(module)s] %(message)s",
)

logging.info(f"Starting optimization")

Running this gives no output. If I remove the import mjcf I do get output.

surgura avatar Jul 01 '22 18:07 surgura

I recently noticed this behavior as well. The standard handler <StreamHandler <stderr> (NOTSET)> is added by the first log call (either absl or standard logging). The dm_control code base just happens to log a few messages during start-up. You can see those log messages by setting the absl log level flag or simply like this:

import logging
logging.basicConfig(level=logging.DEBUG)
import dm_control.mjcf

will print something like

INFO:absl:MUJOCO_GL is not set, so an OpenGL backend will be chosen automatically.
INFO:absl:Successfully imported OpenGL backend: glfw
INFO:absl:MuJoCo library version is: 213

You can still use basicConfig by setting force=True, which will remove any root handlers, i.e. logging.basicConfig(level=logging.INFO, format='[%(name)s] %(message)s', force=True)

JeanElsner avatar Nov 21 '22 14:11 JeanElsner