From 8aa05fc5c34fa0fff3d0c8efa80a4e58d331796b Mon Sep 17 00:00:00 2001 From: Mahimn Date: Tue, 19 May 2026 10:06:51 -0400 Subject: [PATCH] Scope logToFile and logToConsole handlers to ib_async logger Both helpers were attaching their handlers to the root logger via `logging.getLogger()`, so calling them captured every log record in the process, not just records from ib_async. Attach handlers to `logging.getLogger("ib_async")` instead, and tighten the duplicate-detection check in `logToConsole` to inspect the ib_async namespace's own handlers plus root's (since records propagate up). The v0.9.67 fix referenced in `docs/changelog.rst:437` addressed the level-pollution side of this but left the handler attachment on root. Fixes #24 --- ib_async/util.py | 24 +++------ tests/test_log_scoping.py | 105 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 113 insertions(+), 16 deletions(-) create mode 100644 tests/test_log_scoping.py diff --git a/ib_async/util.py b/ib_async/util.py index 65a6a07..4a30cf3 100644 --- a/ib_async/util.py +++ b/ib_async/util.py @@ -232,12 +232,8 @@ def allowCtrlC(): def logToFile(path, level=logging.INFO): """Create a log handler that logs to the given file.""" - logger = logging.getLogger() - if logger.handlers: - logging.getLogger("ib_async").setLevel(level) - else: - logger.setLevel(level) - + logger = logging.getLogger("ib_async") + logger.setLevel(level) formatter = logging.Formatter("%(asctime)s %(name)s %(levelname)s %(message)s") handler = logging.FileHandler(path) handler.setFormatter(formatter) @@ -246,20 +242,16 @@ def logToFile(path, level=logging.INFO): def logToConsole(level=logging.INFO): """Create a log handler that logs to the console.""" - logger = logging.getLogger() + logger = logging.getLogger("ib_async") + logger.setLevel(level) + # Records propagate up to root, so a stderr handler anywhere in the + # ib_async + root handler set is enough to print our logs. stdHandlers = [ h - for h in logger.handlers + for h in (*logger.handlers, *logging.getLogger().handlers) if type(h) is logging.StreamHandler and h.stream is sys.stderr ] - - if stdHandlers: - # if a standard stream handler already exists, use it and - # set the log level for the ib_async namespace only - logging.getLogger("ib_async").setLevel(level) - else: - # else create a new handler - logger.setLevel(level) + if not stdHandlers: formatter = logging.Formatter("%(asctime)s %(name)s %(levelname)s %(message)s") handler = logging.StreamHandler() handler.setFormatter(formatter) diff --git a/tests/test_log_scoping.py b/tests/test_log_scoping.py new file mode 100644 index 0000000..7491541 --- /dev/null +++ b/tests/test_log_scoping.py @@ -0,0 +1,105 @@ +"""logToFile and logToConsole must attach their handlers to the +``ib_async`` logger rather than to root, so an application's other log +records (or library logs from unrelated packages) are not silently teed +into the ib_async-configured destinations. + +The ib_insync v0.9.67 changelog entry (``docs/changelog.rst:437``, +ib_insync issue #361) referenced this concern but only addressed the +level-pollution side. Handler attachment was left on root, which these +tests pin down. +""" + +import logging +import sys + +import ib_async as ibi + + +def test_logToFile_attaches_handler_to_ib_async_only(tmp_path): + """The FileHandler should land on the ib_async logger and not on + root, so records from unrelated loggers are not written to the file.""" + path = tmp_path / "ib.log" + root = logging.getLogger() + ib_logger = logging.getLogger("ib_async") + root_before = list(root.handlers) + ib_before = list(ib_logger.handlers) + + ibi.util.logToFile(path) + added = [h for h in ib_logger.handlers if h not in ib_before] + try: + assert list(root.handlers) == root_before + assert len(added) == 1 + assert isinstance(added[0], logging.FileHandler) + + logging.getLogger("ib_async.test").info("ib-async-record") + third = logging.getLogger("third_party") + third.setLevel(logging.INFO) + third.info("third-party-record") + for h in added: + h.flush() + + contents = path.read_text() + assert "ib-async-record" in contents + assert "third-party-record" not in contents + finally: + for h in added: + ib_logger.removeHandler(h) + h.close() + + +def test_logToConsole_attaches_handler_to_ib_async_only(): + """The StreamHandler should land on the ib_async logger and not on + root.""" + root = logging.getLogger() + ib_logger = logging.getLogger("ib_async") + root_before = list(root.handlers) + ib_before = list(ib_logger.handlers) + + ibi.util.logToConsole() + added = [h for h in ib_logger.handlers if h not in ib_before] + try: + assert list(root.handlers) == root_before + assert len(added) == 1 + assert isinstance(added[0], logging.StreamHandler) + assert added[0].stream is sys.stderr + finally: + for h in added: + ib_logger.removeHandler(h) + + +def test_logToConsole_skips_duplicate_handler_on_repeat_call(): + """A second call to logToConsole must not add a duplicate stderr + handler to the ib_async logger.""" + ib_logger = logging.getLogger("ib_async") + ib_before = list(ib_logger.handlers) + added: list[logging.Handler] = [] + try: + ibi.util.logToConsole() + added = [h for h in ib_logger.handlers if h not in ib_before] + first_count = len(ib_logger.handlers) + + ibi.util.logToConsole() + assert len(ib_logger.handlers) == first_count + finally: + for h in added: + ib_logger.removeHandler(h) + + +def test_logToConsole_skips_when_root_already_has_stderr_handler(): + """When root already has a stderr handler, logToConsole must not add + a duplicate to ib_async (records propagate up to root, so the existing + handler will already print them).""" + root = logging.getLogger() + ib_logger = logging.getLogger("ib_async") + root_before = list(root.handlers) + ib_before = list(ib_logger.handlers) + + user_handler = logging.StreamHandler() # defaults to sys.stderr + root.addHandler(user_handler) + try: + ibi.util.logToConsole() + ib_added = [h for h in ib_logger.handlers if h not in ib_before] + assert ib_added == [] + assert list(root.handlers) == root_before + [user_handler] + finally: + root.removeHandler(user_handler)