h5pyd icon indicating copy to clipboard operation
h5pyd copied to clipboard

`logging.info` call forces downstream package loggers to emit messages twice

Open ppinchuk opened this issue 1 year ago • 0 comments

The logging.info calls added recently here https://github.com/HDFGroup/h5pyd/blob/ca1f8aeac9db5423b602da4f28169928c35f2831/h5pyd/_hl/openid.py#L14 and here https://github.com/HDFGroup/h5pyd/blob/ca1f8aeac9db5423b602da4f28169928c35f2831/h5pyd/_hl/openid.py#L23 (and perhaps others elsewhere) are invoked during the import step. This is often too early for handlers to be added to the root logger, in which case the Python logging library calls logging.basicConfig(). This adds a default StreamHandler that processes all logging messages to stderr in addition to any other handlers that the user adds later. Typically, the end result for any user that adds their own StreamHandler is that log messages are emitted twice - once to stdout and once to stderr.

This is similar to issues described here and here.

Example

This example was taken from the SO link above and modified slightly to show the problem using h5pyd.

test.py

import h5pyd
import logging


def test_a(logger):
    logger.debug("debug")
    logger.info("info")
    logger.warning("warning")
    logger.error("error")


if __name__ == "__main__":
    # Custom logger.
    logger = logging.getLogger("test")

    formatter = logging.Formatter('[%(levelname)s] %(message)s')
    handler = logging.StreamHandler()
    handler.setFormatter(formatter)

    logger.setLevel(logging.DEBUG)
    logger.addHandler(handler)

    test_a(logger)

A clean install (i.e. new conda environment + pip install h5pyd) gives the following output when running the file above:

[DEBUG] debug
DEBUG:test:debug
[INFO] info
INFO:test:info
[WARNING] warning
WARNING:test:warning
[ERROR] error
ERROR:test:error

Instead, the expected output (which can be achieved by removing the import h5pyd line above) is:

[DEBUG] debug
[INFO] info
[WARNING] warning
[ERROR] error

Interestingly, the missing import messages are not actually recorded. Not sure why that is the case.

Any support with this issue would be appreciated. Thanks!

ppinchuk avatar Aug 03 '23 22:08 ppinchuk