From 4bd4587f32d541b6679161293ef72d0169610db9 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?V=C3=ADt=20Zikmund?=
<75443448+vit-zikmund@users.noreply.github.com>
Date: Sun, 11 Feb 2024 13:21:11 +0100
Subject: [PATCH] Fix debug logging for `build` with a build script (#8760)
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit
Co-authored-by: Randy Döring <30527984+radoering@users.noreply.github.com>
---
src/poetry/console/logging/io_formatter.py | 38 +++++++++-
src/poetry/utils/env/__init__.py | 16 +---
src/poetry/utils/env/env_manager.py | 2 +-
tests/console/logging/__init__.py | 0
tests/console/logging/test_io_formatter.py | 85 ++++++++++++++++++++++
tests/utils/env/test_env_manager.py | 12 +++
6 files changed, 137 insertions(+), 16 deletions(-)
create mode 100644 tests/console/logging/__init__.py
create mode 100644 tests/console/logging/test_io_formatter.py
diff --git a/src/poetry/console/logging/io_formatter.py b/src/poetry/console/logging/io_formatter.py
index 274e29e2504..013150130a9 100644
--- a/src/poetry/console/logging/io_formatter.py
+++ b/src/poetry/console/logging/io_formatter.py
@@ -1,7 +1,10 @@
from __future__ import annotations
import logging
+import sys
+import textwrap
+from pathlib import Path
from typing import TYPE_CHECKING
from poetry.console.logging.filters import POETRY_FILTER
@@ -32,8 +35,37 @@ def format(self, record: LogRecord) -> str:
record.msg = msg
+ formatted = super().format(record)
+
if not POETRY_FILTER.filter(record):
- # prefix third-party packages with name for easier debugging
- record.msg = f"[{record.name}] {record.msg}"
+ # prefix all lines from third-party packages for easier debugging
+ formatted = textwrap.indent(
+ formatted, f"[{_log_prefix(record)}] ", lambda line: True
+ )
+
+ return formatted
+
+
+def _log_prefix(record: LogRecord) -> str:
+ prefix = _path_to_package(Path(record.pathname)) or record.module
+ if record.name != "root":
+ prefix = ":".join([prefix, record.name])
+ return prefix
+
- return super().format(record)
+def _path_to_package(path: Path) -> str | None:
+ """Return main package name from the LogRecord.pathname."""
+ prefix: Path | None = None
+ # Find the most specific prefix in sys.path.
+ # We have to search the entire sys.path because a subsequent path might be
+ # a sub path of the first match and thereby a better match.
+ for syspath in sys.path:
+ if (
+ prefix and prefix in (p := Path(syspath)).parents and p in path.parents
+ ) or (not prefix and (p := Path(syspath)) in path.parents):
+ prefix = p
+ if not prefix:
+ # this is unexpected, but let's play it safe
+ return None
+ path = path.relative_to(prefix)
+ return path.parts[0] # main package name
diff --git a/src/poetry/utils/env/__init__.py b/src/poetry/utils/env/__init__.py
index ed22bb3797b..e99abda922f 100644
--- a/src/poetry/utils/env/__init__.py
+++ b/src/poetry/utils/env/__init__.py
@@ -67,25 +67,18 @@ def build_environment(
"""
if not env or poetry.package.build_script:
with ephemeral_environment(executable=env.python if env else None) as venv:
- overwrite = (
- io is not None and io.output.is_decorated() and not io.is_debug()
- )
-
if io:
- if not overwrite:
- io.write_error_line("")
-
requires = [
f"{requirement}"
for requirement in poetry.pyproject.build_system.requires
]
- io.overwrite_error(
+ io.write_error_line(
"Preparing build environment with build-system requirements"
f" {', '.join(requires)}"
)
- venv.run_pip(
+ output = venv.run_pip(
"install",
"--disable-pip-version-check",
"--ignore-installed",
@@ -93,9 +86,8 @@ def build_environment(
*poetry.pyproject.build_system.requires,
)
- if overwrite:
- assert io is not None
- io.write_error_line("")
+ if io and io.is_debug() and output:
+ io.write_error(output)
yield venv
else:
diff --git a/src/poetry/utils/env/env_manager.py b/src/poetry/utils/env/env_manager.py
index ba91f145d22..660b02ca1bf 100644
--- a/src/poetry/utils/env/env_manager.py
+++ b/src/poetry/utils/env/env_manager.py
@@ -675,7 +675,7 @@ def build_venv(
args.append(str(path))
- cli_result = virtualenv.cli_run(args)
+ cli_result = virtualenv.cli_run(args, setup_logging=False)
# Exclude the venv folder from from macOS Time Machine backups
# TODO: Add backup-ignore markers for other platforms too
diff --git a/tests/console/logging/__init__.py b/tests/console/logging/__init__.py
new file mode 100644
index 00000000000..e69de29bb2d
diff --git a/tests/console/logging/test_io_formatter.py b/tests/console/logging/test_io_formatter.py
new file mode 100644
index 00000000000..78ffcc21346
--- /dev/null
+++ b/tests/console/logging/test_io_formatter.py
@@ -0,0 +1,85 @@
+from __future__ import annotations
+
+from logging import LogRecord
+from pathlib import Path
+from typing import TYPE_CHECKING
+
+import pytest
+
+from poetry.console.logging.io_formatter import IOFormatter
+from poetry.console.logging.io_formatter import _log_prefix
+from poetry.console.logging.io_formatter import _path_to_package
+
+
+if TYPE_CHECKING:
+ from pytest_mock import MockerFixture
+
+
+@pytest.mark.parametrize(
+ ("record_name", "record_pathname", "record_msg", "expected"),
+ [
+ ("poetry", "foo/bar.py", "msg", "msg"),
+ ("poetry.core", "foo/bar.py", "msg", "msg"),
+ ("baz", "syspath/foo/bar.py", "msg", "[foo:baz] msg"),
+ ("root", "syspath/foo/bar.py", "1\n\n2", "[foo] 1\n[foo] \n[foo] 2"),
+ ],
+)
+def test_format(
+ mocker: MockerFixture,
+ record_name: str,
+ record_pathname: str,
+ record_msg: str,
+ expected: str,
+) -> None:
+ mocker.patch("sys.path", [str(Path("syspath"))])
+ record = LogRecord(record_name, 0, record_pathname, 0, record_msg, (), None)
+ formatter = IOFormatter()
+ assert formatter.format(record) == expected
+
+
+@pytest.mark.parametrize(
+ ("record_name", "record_pathname", "expected"),
+ [
+ ("root", "syspath/foo/bar.py", "foo"),
+ ("baz", "syspath/foo/bar.py", "foo:baz"),
+ ("baz", "unexpected/foo/bar.py", "bar:baz"),
+ ],
+)
+def test_log_prefix(
+ mocker: MockerFixture,
+ record_name: str,
+ record_pathname: str,
+ expected: str,
+) -> None:
+ mocker.patch("sys.path", [str(Path("syspath"))])
+ record = LogRecord(record_name, 0, record_pathname, 0, "msg", (), None)
+ assert _log_prefix(record) == expected
+
+
+@pytest.mark.parametrize(
+ ("path", "expected"),
+ [
+ ("python-l/lib/python3.9/site-packages/foo/bar/baz.py", "foo"), # Linux
+ ("python-w/lib/site-packages/foo/bar/baz.py", "foo"), # Windows
+ ("unexpected/foo/bar/baz.py", None), # unexpected
+ ],
+)
+def test_path_to_package(
+ mocker: MockerFixture, path: str, expected: str | None
+) -> None:
+ mocker.patch(
+ "sys.path",
+ # We just put the Linux and the Windows variants in the path,
+ # so we do not have to create different mocks based on the subtest.
+ [
+ # On Linux, only the site-packages directory is in the path.
+ str(Path("python-l/lib/python3.9/site-packages")),
+ # On Windows, both the base directory and the site-packages directory
+ # are in the path.
+ str(Path("python-w")),
+ str(Path("python-w/other")), # this one is just to test for robustness
+ str(Path("python-w/lib/site-packages")),
+ str(Path("python-w/lib")), # this one is just to test for robustness
+ ],
+ )
+ assert _path_to_package(Path(path)) == expected
diff --git a/tests/utils/env/test_env_manager.py b/tests/utils/env/test_env_manager.py
index 995d99ab4e3..0c8ba7f99cf 100644
--- a/tests/utils/env/test_env_manager.py
+++ b/tests/utils/env/test_env_manager.py
@@ -1,5 +1,6 @@
from __future__ import annotations
+import logging
import os
import sys
@@ -27,6 +28,7 @@
from collections.abc import Callable
from collections.abc import Iterator
+ from _pytest.logging import LogCaptureFixture
from pytest_mock import MockerFixture
from poetry.poetry import Poetry
@@ -1231,6 +1233,16 @@ def mock_check_output(cmd: str, *args: Any, **kwargs: Any) -> str:
)
+def test_build_venv_does_not_change_loglevel(
+ tmp_path: Path, manager: EnvManager, caplog: LogCaptureFixture
+) -> None:
+ # see https://github.com/python-poetry/poetry/pull/8760
+ venv_path = tmp_path / "venv"
+ caplog.set_level(logging.DEBUG)
+ manager.build_venv(venv_path)
+ assert logging.root.level == logging.DEBUG
+
+
@pytest.mark.skipif(sys.platform != "darwin", reason="requires darwin")
def test_venv_backup_exclusion(tmp_path: Path, manager: EnvManager) -> None:
import xattr