Add colcon_core.logging.get_effective_console_level function (#650)

When colcon routes log messages to log files at a different level from
the console, it makes it a little more convoluted to determine what log
level is actually set.

When we're utilizing non-colcon libraries that also use python's logging
module, we'll typically want to "synchronize" colcon's configured log
level with the other library. This function can be used to determine
what level colcon's console logging is set to.

colcon_core/executor/sequential.py

@@ -10,6 +10,7 @@
 from colcon_core.executor import ExecutorExtensionPoint
 from colcon_core.executor import OnError
 from colcon_core.logging import colcon_logger
+from colcon_core.logging import get_effective_console_level
 from colcon_core.plugin_system import satisfies_version
 from colcon_core.subprocess import new_event_loop
 from colcon_core.subprocess import SIGINT_RESULT
@@ -32,7 +33,8 @@ def __init__(self):  # noqa: D107
     def execute(self, args, jobs, *, on_error=OnError.interrupt):  # noqa: D102
         # avoid debug message from asyncio when colcon uses debug log level
         asyncio_logger = logging.getLogger('asyncio')
-        asyncio_logger.setLevel(logging.INFO)
+        log_level = get_effective_console_level(colcon_logger)
+        asyncio_logger.setLevel(log_level)
 
         rc = 0
         loop = new_event_loop()

colcon_core/logging.py

@@ -127,3 +127,20 @@ def format_message_with_relative_time(record):
     logger.setLevel(1)
 
     return handler
+
+
+def get_effective_console_level(logger):
+    """
+    Determine the effective log level of to the console.
+
+    On a typical logger, this is the same as getEffectiveLevel(). After a call
+    to add_file_handler, this will continue to return the same level though
+    getEffectiveLevel() will now always return ``1``.
+
+    :param logger: The logger to inspect
+    :returns: the log level
+    """
+    for handler in logger.handlers:
+        if isinstance(handler, logging.StreamHandler):
+            return handler.level
+    return logger.getEffectiveLevel()

test/test_logging.py

@@ -6,6 +6,7 @@
 from unittest.mock import Mock
 
 from colcon_core.logging import add_file_handler
+from colcon_core.logging import get_effective_console_level
 from colcon_core.logging import get_numeric_log_level
 from colcon_core.logging import set_logger_level_from_env
 import pytest
@@ -76,3 +77,28 @@ def test_add_file_handler(tmpdir):
 
     # check only that we logged SOMETHING to the file
     assert log_path.stat().st_size > 10
+
+
+def test_get_effective_console_level(tmpdir):
+    logger = logging.getLogger('test_sync_console_log_level')
+
+    # no level set
+    level = get_effective_console_level(logger)
+    assert level == logger.getEffectiveLevel()
+
+    # change the level to ERROR
+    logger.setLevel(logging.ERROR)
+    level = get_effective_console_level(logger)
+    assert level == logger.getEffectiveLevel() == logging.ERROR
+
+    # after add_file_handler
+    log_path = Path(tmpdir) / 'test_add_file_handler.log'
+    log_path.touch()
+    try:
+        add_file_handler(logger, log_path)
+        level = get_effective_console_level(logger)
+        assert level == logging.ERROR
+    finally:
+        for handler in logger.handlers:
+            logger.removeHandler(handler)
+            handler.close()