Merge pull request #3042 from abravalheri/issue-3038

Ensure log level is set correctly (and `setuptools.logging.set_threshold` is called)

2 files changed, 42 insertions, 0 deletions

diff --git a/setuptools/logging.py b/setuptools/logging.py
index dbead6e6..15b57613 100644
--- a/setuptools/logging.py
+++ b/setuptools/logging.py
@@ -24,6 +24,12 @@ def configure():
         format="{message}", style='{', handlers=handlers, level=logging.DEBUG)
     monkey.patch_func(set_threshold, distutils.log, 'set_threshold')
 
+    # For some reason `distutils.log` module is getting cached in `distutils.dist`
+    # and then loaded again when patched,
+    # implying: id(distutils.log) != id(distutils.dist.log).
+    # Make sure the same module object is used everywhere:
+    distutils.dist.log = distutils.log
+
 
 def set_threshold(level):
     logging.root.setLevel(level*10)
diff --git a/setuptools/tests/test_logging.py b/setuptools/tests/test_logging.py
new file mode 100644
index 00000000..a5ddd56d
--- /dev/null
+++ b/setuptools/tests/test_logging.py
@@ -0,0 +1,36 @@
+import logging
+
+import pytest
+
+
+setup_py = """\
+from setuptools import setup
+
+setup(
+    name="test_logging",
+    version="0.0"
+)
+"""
+
+
+@pytest.mark.parametrize(
+    "flag, expected_level", [("--dry-run", "INFO"), ("--verbose", "DEBUG")]
+)
+def test_verbosity_level(tmp_path, monkeypatch, flag, expected_level):
+    """Make sure the correct verbosity level is set (issue #3038)"""
+    import setuptools  # noqa: Import setuptools to monkeypatch distutils
+    import distutils  # <- load distutils after all the patches take place
+
+    logger = logging.Logger(__name__)
+    monkeypatch.setattr(logging, "root", logger)
+    unset_log_level = logger.getEffectiveLevel()
+    assert logging.getLevelName(unset_log_level) == "NOTSET"
+
+    setup_script = tmp_path / "setup.py"
+    setup_script.write_text(setup_py)
+    dist = distutils.core.run_setup(setup_script, stop_after="init")
+    dist.script_args = [flag, "sdist"]
+    dist.parse_command_line()  # <- where the log level is set
+    log_level = logger.getEffectiveLevel()
+    log_level_name = logging.getLevelName(log_level)
+    assert log_level_name == expected_level