Repository: pypa/build
Pull request #749 (2024-03-01 19:26:40)

main: improve console output

layday: <img width="1054" alt="Screenshot 2024-03-01 at 21 28 30" src="https://github.com/pypa/build/assets/31134424/70a35d42-5e6f-471e-abb8-a4968bf24a7b">

henryiii: Would it make sense to remove the bold on the package names? I think that would look a little more distinct:

![Screenshot 2024-03-01 at 2 37 30 PM](https://github.com/pypa/build/assets/4616906/27ca1267-d4c5-4c41-91c0-e13fd09de1a6)


layday: That makes sense, I've changed it.
henryiii: Much better, I think:

![Screenshot 2024-03-01 at 3 55 57 PM](https://github.com/pypa/build/assets/4616906/142ad102-ac0e-4e44-8ca5-d9764a9c7634)

layday: Any thoughts on the verbosity option?
henryiii: Basically just passes through to the underlying pip? Seems fine.

Patch:
diff --git a/pyproject.toml b/pyproject.toml
index 93b0177..0b58724 100644
--- a/pyproject.toml
+++ b/pyproject.toml
@@ -114,6 +114,7 @@ xfail_strict = true
 junit_family = "xunit2"
 norecursedirs = "tests/integration/*"
 markers = [
+  "contextvars",
   "isolated",
   "pypy3323bug",
   "network",
diff --git a/src/build/__main__.py b/src/build/__main__.py
index f009178..b8cf170 100644
--- a/src/build/__main__.py
+++ b/src/build/__main__.py
@@ -4,6 +4,7 @@ from __future__ import annotations
 
 import argparse
 import contextlib
+import contextvars
 import os
 import platform
 import shutil
@@ -20,7 +21,7 @@ from typing import NoReturn, TextIO
 
 import build
 
-from . import ProjectBuilder
+from . import ProjectBuilder, _ctx
 from ._exceptions import BuildBackendException, BuildException, FailedProcessError
 from ._types import ConfigSettings, Distribution, StrPath
 from .env import DefaultIsolatedEnv
@@ -38,21 +39,21 @@ _COLORS = {
 _NO_COLORS = {color: '' for color in _COLORS}
 
 
-def _init_colors() -> dict[str, str]:
+_styles = contextvars.ContextVar('_styles', default=_COLORS)
+
+
+def _init_colors() -> None:
     if 'NO_COLOR' in os.environ:
         if 'FORCE_COLOR' in os.environ:
             warnings.warn('Both NO_COLOR and FORCE_COLOR environment variables are set, disabling color', stacklevel=2)
-        return _NO_COLORS
+        _styles.set(_NO_COLORS)
     elif 'FORCE_COLOR' in os.environ or sys.stdout.isatty():
-        return _COLORS
-    return _NO_COLORS
-
+        return
+    _styles.set(_NO_COLORS)
 
-_STYLES = _init_colors()
 
-
-def _cprint(fmt: str = '', msg: str = '') -> None:
-    print(fmt.format(msg, **_STYLES), flush=True)
+def _cprint(fmt: str = '', msg: str = '', file: TextIO | None = None) -> None:
+    print(fmt.format(msg, **_styles.get()), file=file, flush=True)
 
 
 def _showwarning(
@@ -66,7 +67,27 @@ def _showwarning(
     _cprint('{yellow}WARNING{reset} {}', str(message))
 
 
-def _setup_cli() -> None:
+_max_terminal_width = shutil.get_terminal_size().columns - 2
+
+
+_fill = partial(textwrap.fill, subsequent_indent='  ', width=_max_terminal_width)
+
+
+def _log(message: str, *, origin: tuple[str, ...] | None = None) -> None:
+    if origin is None:
+        (first, *rest) = message.splitlines()
+        _cprint('{bold}{}{reset}', _fill(first, initial_indent='* '))
+        for line in rest:
+            print(_fill(line, initial_indent='  '))
+
+    elif origin[0] == 'subprocess':
+        initial_indent = '> ' if origin[1] == 'cmd' else '< '
+        file = sys.stderr if origin[1] == 'stderr' else None
+        for line in message.splitlines():
+            _cprint('{dim}{}{reset}', _fill(line, initial_indent=initial_indent), file=file)
+
+
+def _setup_cli(*, verbosity: int) -> None:
     warnings.showwarning = _showwarning
 
     if platform.system() == 'Windows':
@@ -77,6 +98,11 @@ def _setup_cli() -> None:
         except ModuleNotFoundError:
             pass
 
+    _init_colors()
+
+    _ctx.LOGGER.set(_log)
+    _ctx.VERBOSITY.set(verbosity)
+
 
 def _error(msg: str, code: int = 1) -> NoReturn:  # pragma: no cover
     """
@@ -89,18 +115,6 @@ def _error(msg: str, code: int = 1) -> NoReturn:  # pragma: no cover
     raise SystemExit(code)
 
 
-class _ProjectBuilder(ProjectBuilder):
-    @staticmethod
-    def log(message: str) -> None:
-        _cprint('{bold}* {}{reset}', message)
-
-
-class _DefaultIsolatedEnv(DefaultIsolatedEnv):
-    @staticmethod
-    def log(message: str) -> None:
-        _cprint('{bold}* {}{reset}', message)
-
-
 def _format_dep_chain(dep_chain: Sequence[str]) -> str:
     return ' -> '.join(dep.partition(';')[0].strip() for dep in dep_chain)
 
@@ -111,8 +125,8 @@ def _build_in_isolated_env(
     distribution: Distribution,
     config_settings: ConfigSettings | None,
 ) -> str:
-    with _DefaultIsolatedEnv() as env:
-        builder = _ProjectBuilder.from_isolated_env(env, srcdir)
+    with DefaultIsolatedEnv() as env:
+        builder = ProjectBuilder.from_isolated_env(env, srcdir)
         # first install the build dependencies
         env.install(builder.build_system_requires)
         # then get the extra required dependencies from the backend (which was installed in the call above :P)
@@ -127,7 +141,7 @@ def _build_in_current_env(
     config_settings: ConfigSettings | None,
     skip_dependency_check: bool = False,
 ) -> str:
-    builder = _ProjectBuilder(srcdir)
+    builder = ProjectBuilder(srcdir)
 
     if not skip_dependency_check:
         missing = builder.check_dependencies(distribution, config_settings or {})
@@ -176,6 +190,10 @@ def _handle_build_error() -> Iterator[None]:
             tb = traceback.format_exc(-1)
         _cprint('\n{dim}{}{reset}\n', tb.strip('\n'))
         _error(str(e))
+    except Exception as e:  # pragma: no cover
+        tb = traceback.format_exc().strip('\n')
+        _cprint('\n{dim}{}{reset}\n', tb)
+        _error(str(e))
 
 
 def _natural_language_list(elements: Sequence[str]) -> str:
@@ -250,7 +268,7 @@ def build_package_via_sdist(
         with tarfile.TarFile.open(sdist) as t:
             t.extractall(sdist_out)
             try:
-                _ProjectBuilder.log(f'Building {_natural_language_list(distributions)} from sdist')
+                _ctx.log(f'Building {_natural_language_list(distributions)} from sdist')
                 srcdir = os.path.join(sdist_out, sdist_name[: -len('.tar.gz')])
                 for distribution in distributions:
                     out = _build(isolation, srcdir, outdir, distribution, config_settings, skip_dependency_check)
@@ -283,12 +301,9 @@ def main_parser() -> argparse.ArgumentParser:
             ).strip(),
             '    ',
         ),
-        formatter_class=partial(
-            argparse.RawDescriptionHelpFormatter,
-            # Prevent argparse from taking up the entire width of the terminal window
-            # which impedes readability.
-            width=min(shutil.get_terminal_size().columns - 2, 127),
-        ),
+        # Prevent argparse from taking up the entire width of the terminal window
+        # which impedes readability.
+        formatter_class=partial(argparse.RawDescriptionHelpFormatter, width=min(_max_terminal_width, 127)),
     )
     parser.add_argument(
         'srcdir',
@@ -303,6 +318,14 @@ def main_parser() -> argparse.ArgumentParser:
         action='version',
         version=f"build {build.__version__} ({','.join(build.__path__)})",
     )
+    parser.add_argument(
+        '--verbose',
+        '-v',
+        dest='verbosity',
+        action='count',
+        default=0,
+        help='increase verbosity',
+    )
     parser.add_argument(
         '--sdist',
         '-s',
@@ -354,12 +377,13 @@ def main(cli_args: Sequence[str], prog: str | None = None) -> None:
     :param cli_args: CLI arguments
     :param prog: Program name to show in help text
     """
-    _setup_cli()
     parser = main_parser()
     if prog:
         parser.prog = prog
     args = parser.parse_args(cli_args)
 
+    _setup_cli(verbosity=args.verbosity)
+
     distributions: list[Distribution] = []
     config_settings = {}
 
@@ -387,19 +411,15 @@ def main(cli_args: Sequence[str], prog: str | None = None) -> None:
     else:
         build_call = build_package_via_sdist
         distributions = ['wheel']
-    try:
-        with _handle_build_error():
-            built = build_call(
-                args.srcdir, outdir, distributions, config_settings, not args.no_isolation, args.skip_dependency_check
-            )
-            artifact_list = _natural_language_list(
-                ['{underline}{}{reset}{bold}{green}'.format(artifact, **_STYLES) for artifact in built]
-            )
-            _cprint('{bold}{green}Successfully built {}{reset}', artifact_list)
-    except Exception as e:  # pragma: no cover
-        tb = traceback.format_exc().strip('\n')
-        _cprint('\n{dim}{}{reset}\n', tb)
-        _error(str(e))
+
+    with _handle_build_error():
+        built = build_call(
+            args.srcdir, outdir, distributions, config_settings, not args.no_isolation, args.skip_dependency_check
+        )
+        artifact_list = _natural_language_list(
+            ['{underline}{}{reset}{bold}{green}'.format(artifact, **_styles.get()) for artifact in built]
+        )
+        _cprint('{bold}{green}Successfully built {}{reset}', artifact_list)
 
 
 def entrypoint() -> None:
diff --git a/src/build/_builder.py b/src/build/_builder.py
index ba571e1..cfd7a5e 100644
--- a/src/build/_builder.py
+++ b/src/build/_builder.py
@@ -4,7 +4,6 @@ from __future__ import annotations
 
 import contextlib
 import difflib
-import logging
 import os
 import subprocess
 import sys
@@ -16,7 +15,7 @@ from typing import Any, Mapping, Sequence, TypeVar
 
 import pyproject_hooks
 
-from . import env
+from . import _ctx, env
 from ._compat import tomllib
 from ._exceptions import (
     BuildBackendException,
@@ -37,9 +36,6 @@ _DEFAULT_BACKEND = {
 }
 
 
-_logger = logging.getLogger(__name__)
-
-
 def _find_typo(dictionary: Mapping[str, str], expected: str) -> None:
     for obj in dictionary:
         if difflib.SequenceMatcher(None, expected, obj).ratio() >= 0.8:
@@ -216,7 +212,7 @@ class ProjectBuilder:
             (``sdist`` or ``wheel``)
         :param config_settings: Config settings for the build backend
         """
-        self.log(f'Getting build dependencies for {distribution}...')
+        _ctx.log(f'Getting build dependencies for {distribution}...')
         hook_name = f'get_requires_for_build_{distribution}'
         get_requires = getattr(self._hook, hook_name)
 
@@ -252,7 +248,7 @@ class ProjectBuilder:
         :param config_settings: Config settings for the build backend
         :returns: The full path to the prepared metadata directory
         """
-        self.log(f'Getting metadata for {distribution}...')
+        _ctx.log(f'Getting metadata for {distribution}...')
         try:
             return self._call_backend(
                 f'prepare_metadata_for_build_{distribution}',
@@ -282,7 +278,7 @@ class ProjectBuilder:
             previous ``prepare`` call on the same ``distribution`` kind
         :returns: The full path to the built distribution
         """
-        self.log(f'Building {distribution}...')
+        _ctx.log(f'Building {distribution}...')
         kwargs = {} if metadata_directory is None else {'metadata_directory': metadata_directory}
         return self._call_backend(f'build_{distribution}', output_directory, config_settings, **kwargs)
 
@@ -349,15 +345,3 @@ class ProjectBuilder:
             raise BuildBackendException(exception, f'Backend subprocess exited when trying to invoke {hook}') from None
         except Exception as exception:
             raise BuildBackendException(exception, exc_info=sys.exc_info()) from None
-
-    @staticmethod
-    def log(message: str) -> None:
-        """
-        Log a message.
-
-        The default implementation uses the logging module but this function can be
-        overridden by users to have a different implementation.
-
-        :param message: Message to output
-        """
-        _logger.log(logging.INFO, message, stacklevel=2)
diff --git a/src/build/_ctx.py b/src/build/_ctx.py
new file mode 100644
index 0000000..fae1bd14
--- /dev/null
+++ b/src/build/_ctx.py
@@ -0,0 +1,99 @@
+from __future__ import annotations
+
+import contextvars
+import logging
+import subprocess
+import typing
+
+from collections.abc import Sequence
+from functools import partial
+
+from ._types import StrPath
+
+
+class _Logger(typing.Protocol):  # pragma: no cover
+    def __call__(self, message: str, *, origin: tuple[str, ...] | None = None) -> None:
+        ...
+
+
+_package_name = __spec__.parent  # type: ignore[name-defined]
+_default_logger = logging.getLogger(_package_name)
+
+
+def _log_default(message: str, *, origin: tuple[str, ...] | None = None) -> None:
+    if origin is None:
+        _default_logger.log(logging.INFO, message, stacklevel=2)
+
+
+LOGGER = contextvars.ContextVar('LOGGER', default=_log_default)
+VERBOSITY = contextvars.ContextVar('VERBOSITY', default=0)
+
+
+def log_subprocess_error(error: subprocess.CalledProcessError) -> None:
+    log = LOGGER.get()
+
+    log(subprocess.list2cmdline(error.cmd), origin=('subprocess', 'cmd'))
+
+    for stream_name in ('stdout', 'stderr'):
+        stream = getattr(error, stream_name)
+        if stream:
+            log(stream.decode() if isinstance(stream, bytes) else stream, origin=('subprocess', stream_name))
+
+
+def run_subprocess(cmd: Sequence[StrPath]) -> None:
+    verbosity = VERBOSITY.get()
+
+    if verbosity:
+        import concurrent.futures
+
+        log = LOGGER.get()
+
+        def log_stream(stream_name: str, stream: typing.IO[str]) -> None:
+            for line in stream:
+                log(line, origin=('subprocess', stream_name))
+
+        with concurrent.futures.ThreadPoolExecutor(max_workers=2) as executor, subprocess.Popen(
+            cmd, encoding='utf-8', stdout=subprocess.PIPE, stderr=subprocess.PIPE
+        ) as process:
+            log(subprocess.list2cmdline(cmd), origin=('subprocess', 'cmd'))
+
+            # Logging in sub-thread to more-or-less ensure order of stdout and stderr whilst also
+            # being able to distinguish between the two.
+            concurrent.futures.wait(
+                [executor.submit(partial(log_stream, n, getattr(process, n))) for n in ('stdout', 'stderr')]
+            )
+
+            code = process.wait()
+            if code:
+                raise subprocess.CalledProcessError(code, process.args)
+
+    else:
+        try:
+            subprocess.run(cmd, capture_output=True, check=True)
+        except subprocess.CalledProcessError as error:
+            log_subprocess_error(error)
+            raise
+
+
+if typing.TYPE_CHECKING:
+    log: _Logger
+    verbosity: bool
+
+else:
+
+    def __getattr__(name):
+        if name == 'log':
+            return LOGGER.get()
+        elif name == 'verbosity':
+            return VERBOSITY.get()
+        raise AttributeError(name)  # pragma: no cover
+
+
+__all__ = [
+    'log_subprocess_error',
+    'log',
+    'run_subprocess',
+    'LOGGER',
+    'verbosity',
+    'VERBOSITY',
+]
diff --git a/src/build/_exceptions.py b/src/build/_exceptions.py
index 3d16a76..ff14b63 100644
--- a/src/build/_exceptions.py
+++ b/src/build/_exceptions.py
@@ -1,7 +1,6 @@
 from __future__ import annotations
 
 import subprocess
-import textwrap
 import types
 
 
@@ -57,14 +56,7 @@ class FailedProcessError(Exception):
         self._description = description
 
     def __str__(self) -> str:
-        cmd = ' '.join(self.exception.cmd)
-        description = f"{self._description}\n  Command '{cmd}' failed with return code {self.exception.returncode}"
-        for stream_name in ('stdout', 'stderr'):
-            stream = getattr(self.exception, stream_name)
-            if stream:
-                description += f'\n  {stream_name}:\n'
-                description += textwrap.indent(stream.decode(), '    ')
-        return description
+        return self._description
 
 
 class TypoWarning(Warning):
diff --git a/src/build/env.py b/src/build/env.py
index 50aeb04..6cf47c1 100644
--- a/src/build/env.py
+++ b/src/build/env.py
@@ -3,7 +3,6 @@ from __future__ import annotations
 import abc
 import functools
 import importlib.util
-import logging
 import os
 import platform
 import shutil
@@ -16,13 +15,12 @@ import warnings
 
 from collections.abc import Collection, Mapping
 
+from . import _ctx
+from ._ctx import run_subprocess
 from ._exceptions import FailedProcessError
 from ._util import check_dependency
 
 
-_logger = logging.getLogger(__name__)
-
-
 class IsolatedEnv(typing.Protocol):
     """Isolated build environment ABC."""
 
@@ -99,15 +97,6 @@ def _valid_global_pip() -> bool | None:
         return None
 
 
-def _subprocess(cmd: list[str]) -> None:
-    """Invoke subprocess and output stdout and stderr if it fails."""
-    try:
-        subprocess.run(cmd, check=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
-    except subprocess.CalledProcessError as e:
-        print(e.output.decode(), end='', file=sys.stderr)
-        raise
-
-
 class DefaultIsolatedEnv(IsolatedEnv):
     """An isolated environment which combines venv and virtualenv with pip."""
 
@@ -116,10 +105,10 @@ class DefaultIsolatedEnv(IsolatedEnv):
             self._path = tempfile.mkdtemp(prefix='build-env-')
             # use virtualenv when available (as it's faster than venv)
             if _should_use_virtualenv():
-                self.log('Creating virtualenv isolated environment...')
+                _ctx.log('Creating virtualenv isolated environment...')
                 self._python_executable, self._scripts_dir = _create_isolated_env_virtualenv(self._path)
             else:
-                self.log('Creating venv isolated environment...')
+                _ctx.log('Creating venv isolated environment...')
 
                 # Call ``realpath`` to prevent spurious warning from being emitted
                 # that the venv location has changed on Windows. The username is
@@ -148,12 +137,6 @@ class DefaultIsolatedEnv(IsolatedEnv):
         """The python executable of the isolated build environment."""
         return self._python_executable
 
-    def _pip_args(self) -> list[str]:
-        if _valid_global_pip():
-            return [sys.executable, '-m', 'pip', '--python', self.python_executable]
-        else:
-            return [self.python_executable, '-Im', 'pip']
-
     def make_extra_environ(self) -> dict[str, str]:
         path = os.environ.get('PATH')
         return {'PATH': os.pathsep.join([self._scripts_dir, path]) if path is not None else self._scripts_dir}
@@ -170,37 +153,33 @@ class DefaultIsolatedEnv(IsolatedEnv):
         if not requirements:
             return
 
-        self.log(f'Installing packages in isolated environment... ({", ".join(sorted(requirements))})')
+        _ctx.log('Installing packages in isolated environment:\n' + '\n'.join(f'- {r}' for r in sorted(requirements)))
 
         # pip does not honour environment markers in command line arguments
         # but it does for requirements from a file
         with tempfile.NamedTemporaryFile('w', prefix='build-reqs-', suffix='.txt', delete=False, encoding='utf-8') as req_file:
             req_file.write(os.linesep.join(requirements))
+
         try:
-            cmd = [
-                *self._pip_args(),
+            if _valid_global_pip():
+                cmd = [sys.executable, '-m', 'pip', '--python', self.python_executable]
+            else:
+                cmd = [self.python_executable, '-Im', 'pip']
+
+            if _ctx.verbosity > 1:
+                cmd += [f'-{"v" * (_ctx.verbosity - 1)}']
+
+            cmd += [
                 'install',
                 '--use-pep517',
                 '--no-warn-script-location',
                 '-r',
                 os.path.abspath(req_file.name),
             ]
-            _subprocess(cmd)
+            run_subprocess(cmd)
         finally:
             os.unlink(req_file.name)
 
-    @staticmethod
-    def log(message: str) -> None:
-        """
-        Prints message
-
-        The default implementation uses the logging module but this function can be
-        overwritten by users to have a different implementation.
-
-        :param msg: Message to output
-        """
-        _logger.log(logging.INFO, message, stacklevel=2)
-
 
 def _create_isolated_env_virtualenv(path: str) -> tuple[str, str]:
     """
@@ -256,17 +235,18 @@ def _create_isolated_env_venv(path: str) -> tuple[str, str]:
                 warnings.filterwarnings('ignore', 'check_home argument is deprecated and ignored.', DeprecationWarning)
             venv.EnvBuilder(with_pip=not _valid_global_pip(), symlinks=symlinks).create(path)
     except subprocess.CalledProcessError as exc:
+        _ctx.log_subprocess_error(exc)
         raise FailedProcessError(exc, 'Failed to create venv. Maybe try installing virtualenv.') from None
 
     executable, script_dir, purelib = _find_executable_and_scripts(path)
 
     # Get the version of pip in the environment
     if not _valid_global_pip() and not _has_valid_pip(path=[purelib]):
-        _subprocess([executable, '-m', 'pip', 'install', f'pip>={_minimum_pip_version()}'])
+        run_subprocess([executable, '-m', 'pip', 'install', f'pip>={_minimum_pip_version()}'])
 
     # Avoid the setuptools from ensurepip to break the isolation
     if not _valid_global_pip():
-        _subprocess([executable, '-m', 'pip', 'uninstall', 'setuptools', '-y'])
+        run_subprocess([executable, '-m', 'pip', 'uninstall', 'setuptools', '-y'])
 
     return executable, script_dir
 


Test patch:
diff --git a/tests/conftest.py b/tests/conftest.py
index 807a106..7076bdc 100644
--- a/tests/conftest.py
+++ b/tests/conftest.py
@@ -1,6 +1,7 @@
 # SPDX-License-Identifier: MIT
 
 import contextlib
+import contextvars
 import importlib.metadata
 import os
 import os.path
@@ -10,6 +11,8 @@ import sys
 import sysconfig
 import tempfile
 
+from functools import partial, update_wrapper
+
 import pytest
 
 import build.env
@@ -60,6 +63,16 @@ def is_integration(item):
     return os.path.basename(item.location[0]) == 'test_integration.py'
 
 
+def pytest_runtest_call(item: pytest.Item):
+    if item.get_closest_marker('contextvars'):
+        if isinstance(item, pytest.Function):
+            wrapped_function = partial(contextvars.copy_context().run, item.obj)
+            item.obj = update_wrapper(wrapped_function, item.obj)
+        else:
+            msg = 'cannot rewrap non-function item'
+            raise RuntimeError(msg)
+
+
 @pytest.fixture()
 def local_pip(monkeypatch):
     monkeypatch.setattr(build.env, '_valid_global_pip', lambda: None)
diff --git a/tests/test_ctx_logger.py b/tests/test_ctx_logger.py
new file mode 100644
index 0000000..5c609a5
--- /dev/null
+++ b/tests/test_ctx_logger.py
@@ -0,0 +1,74 @@
+from __future__ import annotations
+
+import logging
+import sys
+
+import pytest
+import pytest_mock
+
+import build._ctx
+
+
+pytestmark = pytest.mark.contextvars
+
+
+def test_default_ctx_logger(caplog: pytest.LogCaptureFixture):
+    build._ctx.log('foo')
+
+    [record] = caplog.records
+    assert record.name == 'build'
+    assert record.levelno == logging.INFO
+    assert record.message == 'foo'
+
+
+def test_default_ctx_logger_only_logs_null_origin_messages(caplog: pytest.LogCaptureFixture):
+    build._ctx.log('foo', origin=None)
+    build._ctx.log('bar', origin=('bar',))
+
+    [record] = caplog.records
+    assert record.message == 'foo'
+
+
+def test_ctx_custom_logger(mocker: pytest_mock.MockerFixture):
+    log_stub = mocker.stub('custom_logger')
+
+    build._ctx.LOGGER.set(log_stub)
+    build._ctx.log('foo')
+
+    log_stub.assert_called_once_with('foo')
+
+
+def test_ctx_custom_logger_with_custom_verbosity(mocker: pytest_mock.MockerFixture):
+    log_stub = mocker.stub('custom_logger')
+
+    def log(message: str, **kwargs):
+        if build._ctx.verbosity >= 9000:
+            log_stub(message)
+
+    build._ctx.LOGGER.set(log)
+    build._ctx.log('foo')
+    build._ctx.VERBOSITY.set(9000)
+    build._ctx.log('bar')
+
+    log_stub.assert_called_once_with('bar')
+
+
+@pytest.mark.parametrize(
+    ('verbosity', 'kwarg_origins'),
+    [
+        (0, []),
+        (1, [('subprocess', 'cmd'), ('subprocess', 'stdout')]),
+    ],
+)
+def test_custom_subprocess_runner_ctx_logging(
+    mocker: pytest_mock.MockerFixture, verbosity: int, kwarg_origins: list[tuple[str, ...]]
+):
+    log_stub = mocker.stub('custom_logger')
+
+    build._ctx.LOGGER.set(log_stub)
+    build._ctx.VERBOSITY.set(verbosity)
+
+    build._ctx.run_subprocess([sys.executable, '-m', 'build', '-V'])
+
+    assert log_stub.call_count == len(kwarg_origins)
+    assert [c.kwargs['origin'] for c in log_stub.call_args_list] == kwarg_origins
diff --git a/tests/test_env.py b/tests/test_env.py
index 379d8e5..93b6a6d 100644
--- a/tests/test_env.py
+++ b/tests/test_env.py
@@ -29,14 +29,14 @@ def test_isolation():
 @pytest.mark.usefixtures('local_pip')
 def test_isolated_environment_install(mocker):
     with build.env.DefaultIsolatedEnv() as env:
-        mocker.patch('build.env._subprocess')
+        mocker.patch('build.env.run_subprocess')
 
         env.install([])
-        build.env._subprocess.assert_not_called()
+        build.env.run_subprocess.assert_not_called()
 
         env.install(['some', 'requirements'])
-        build.env._subprocess.assert_called()
-        args = build.env._subprocess.call_args[0][0][:-1]
+        build.env.run_subprocess.assert_called()
+        args = build.env.run_subprocess.call_args[0][0][:-1]
         assert args == [
             env.python_executable,
             '-Im',
@@ -102,18 +102,15 @@ def test_isolated_env_has_install_still_abstract():
 
 @pytest.mark.pypy3323bug
 def test_isolated_env_log(mocker, caplog, package_test_flit):
-    mocker.patch('build.env._subprocess')
+    mocker.patch('build.env.run_subprocess')
     caplog.set_level(logging.DEBUG)
 
-    builder = build.env.DefaultIsolatedEnv()
-    builder.log('something')  # line number 106
-    with builder as env:
+    with build.env.DefaultIsolatedEnv() as env:
         env.install(['something'])
 
     assert [(record.levelname, record.message) for record in caplog.records] == [
-        ('INFO', 'something'),
         ('INFO', 'Creating venv isolated environment...'),
-        ('INFO', 'Installing packages in isolated environment... (something)'),
+        ('INFO', 'Installing packages in isolated environment:\n- something'),
     ]
 
 
@@ -136,7 +133,7 @@ def test_default_pip_is_never_too_old():
 def test_pip_needs_upgrade_mac_os_11(mocker, pip_version, arch):
     SimpleNamespace = collections.namedtuple('SimpleNamespace', 'version')
 
-    _subprocess = mocker.patch('build.env._subprocess')
+    _subprocess = mocker.patch('build.env.run_subprocess')
     mocker.patch('platform.system', return_value='Darwin')
     mocker.patch('platform.machine', return_value=arch)
     mocker.patch('platform.mac_ver', return_value=('11.0', ('', '', ''), ''))
diff --git a/tests/test_main.py b/tests/test_main.py
index 2ca18e4..ecede88 100644
--- a/tests/test_main.py
+++ b/tests/test_main.py
@@ -1,7 +1,6 @@
 # SPDX-License-Identifier: MIT
 
 import contextlib
-import importlib
 import io
 import os
 import re
@@ -15,6 +14,9 @@ import build
 import build.__main__
 
 
+pytestmark = pytest.mark.contextvars
+
+
 build_open_owner = 'builtins'
 
 cwd = os.getcwd()
@@ -230,14 +232,17 @@ def test_build_package_via_sdist_invalid_distribution(tmp_dir, package_test_setu
             [],
             [
                 '* Creating venv isolated environment...',
-                '* Installing packages in isolated environment... (setuptools >= 42.0.0)',
+                '* Installing packages in isolated environment:',
+                '  - setuptools >= 42.0.0',
                 '* Getting build dependencies for sdist...',
                 '* Building sdist...',
                 '* Building wheel from sdist',
                 '* Creating venv isolated environment...',
-                '* Installing packages in isolated environment... (setuptools >= 42.0.0)',
+                '* Installing packages in isolated environment:',
+                '  - setuptools >= 42.0.0',
                 '* Getting build dependencies for wheel...',
-                '* Installing packages in isolated environment... (wheel)',
+                '* Installing packages in isolated environment:',
+                '  - wheel',
                 '* Building wheel...',
                 'Successfully built test_setuptools-1.0.0.tar.gz and test_setuptools-1.0.0-py2.py3-none-any.whl',
             ],
@@ -260,9 +265,11 @@ def test_build_package_via_sdist_invalid_distribution(tmp_dir, package_test_setu
             ['--wheel'],
             [
                 '* Creating venv isolated environment...',
-                '* Installing packages in isolated environment... (setuptools >= 42.0.0)',
+                '* Installing packages in isolated environment:',
+                '  - setuptools >= 42.0.0',
                 '* Getting build dependencies for wheel...',
-                '* Installing packages in isolated environment... (wheel)',
+                '* Installing packages in isolated environment:',
+                '  - wheel',
                 '* Building wheel...',
                 'Successfully built test_setuptools-1.0.0-py2.py3-none-any.whl',
             ],
@@ -307,14 +314,6 @@ def test_output(package_test_setuptools, tmp_dir, capsys, args, output):
     assert stdout.splitlines() == output
 
 
-@pytest.fixture()
-def main_reload_styles():
-    try:
-        yield
-    finally:
-        importlib.reload(build.__main__)
-
-
 @pytest.mark.pypy3323bug
 @pytest.mark.parametrize(
     ('color', 'stdout_error', 'stdout_body'),
@@ -324,9 +323,9 @@ def main_reload_styles():
             'ERROR ',
             [
                 '* Creating venv isolated environment...',
-                '* Installing packages in isolated environment... (setuptools >= 42.0.0, this is invalid)',
-                '',
-                'Traceback (most recent call last):',
+                '* Installing packages in isolated environment:',
+                '  - setuptools >= 42.0.0',
+                '  - this is invalid',
             ],
         ),
         (
@@ -334,9 +333,9 @@ def main_reload_styles():
             '\33[91mERROR\33[0m ',
             [
                 '\33[1m* Creating venv isolated environment...\33[0m',
-                '\33[1m* Installing packages in isolated environment... (setuptools >= 42.0.0, this is invalid)\33[0m',
-                '',
-                '\33[2mTraceback (most recent call last):',
+                '\33[1m* Installing packages in isolated environment:\33[0m',
+                '  - setuptools >= 42.0.0',
+                '  - this is invalid',
             ],
         ),
     ],
@@ -346,7 +345,6 @@ def main_reload_styles():
 def test_output_env_subprocess_error(
     mocker,
     monkeypatch,
-    main_reload_styles,
     package_test_invalid_requirements,
     tmp_dir,
     capsys,
@@ -363,8 +361,6 @@ def test_output_env_subprocess_error(
     monkeypatch.delenv('NO_COLOR', raising=False)
     monkeypatch.setenv('FORCE_COLOR' if color else 'NO_COLOR', '')
 
-    importlib.reload(build.__main__)  # reload module to set _STYLES
-
     with pytest.raises(SystemExit):
         build.__main__.main([package_test_invalid_requirements, '-o', tmp_dir])
     stdout, stderr = capsys.readouterr()
@@ -375,8 +371,7 @@ def test_output_env_subprocess_error(
 
     # Newer versions of pip also color stderr - strip them if present
     cleaned_stderr = ANSI_STRIP.sub('', '\n'.join(stderr)).strip()
-    assert len(cleaned_stderr.splitlines()) == 1
-    assert cleaned_stderr.startswith('ERROR: Invalid requirement: ')
+    assert cleaned_stderr.startswith('< ERROR: Invalid requirement: ')
 
 
 @pytest.mark.parametrize(
@@ -390,17 +385,17 @@ def test_output_env_subprocess_error(
         (True, {'FORCE_COLOR': ''}, build.__main__._COLORS),
     ],
 )
-def test_colors(mocker, monkeypatch, main_reload_styles, tty, env, colors):
+def test_colors(mocker, monkeypatch, tty, env, colors):
     mocker.patch('sys.stdout.isatty', return_value=tty)
     for key, value in env.items():
         monkeypatch.setenv(key, value)
 
-    importlib.reload(build.__main__)  # reload module to set _STYLES
+    build.__main__._init_colors()
 
-    assert build.__main__._STYLES == colors
+    assert build.__main__._styles.get() == colors
 
 
-def test_colors_conflict(monkeypatch, main_reload_styles):
+def test_colors_conflict(monkeypatch):
     with monkeypatch.context() as m:
         m.setenv('NO_COLOR', '')
         m.setenv('FORCE_COLOR', '')
@@ -409,21 +404,18 @@ def test_colors_conflict(monkeypatch, main_reload_styles):
             UserWarning,
             match='Both NO_COLOR and FORCE_COLOR environment variables are set, disabling color',
         ):
-            importlib.reload(build.__main__)
+            build.__main__._init_colors()
 
-        assert build.__main__._STYLES == build.__main__._NO_COLORS
-
-
-def raise_called_process_err(*args, **kwargs):
-    raise subprocess.CalledProcessError(1, ['test', 'args'], b'stdoutput', b'stderror')
+        assert build.__main__._styles.get() == build.__main__._NO_COLORS
 
 
 def test_venv_fail(monkeypatch, package_test_flit, tmp_dir, capsys):
+    def raise_called_process_err(*args, **kwargs):
+        raise subprocess.CalledProcessError(1, ['test', 'args'], b'stdoutput', b'stderror')
+
     monkeypatch.setattr(venv.EnvBuilder, 'create', raise_called_process_err)
     monkeypatch.setenv('NO_COLOR', '')
 
-    importlib.reload(build.__main__)  # reload module to set _STYLES
-
     with pytest.raises(SystemExit):
         build.__main__.main([package_test_flit, '-o', tmp_dir])
 
@@ -433,12 +425,34 @@ def test_venv_fail(monkeypatch, package_test_flit, tmp_dir, capsys):
         stdout
         == """\
 * Creating venv isolated environment...
+> test args
+< stdoutput
 ERROR Failed to create venv. Maybe try installing virtualenv.
-  Command 'test args' failed with return code 1
-  stdout:
-    stdoutput
-  stderr:
-    stderror
 """
     )
-    assert stderr == ''
+    assert (
+        stderr
+        == """\
+< stderror
+"""
+    )
+
+
+@pytest.mark.parametrize('verbosity', [0, 1])
+def test_verbose_output(
+    capsys: pytest.CaptureFixture,
+    monkeypatch,
+    tmp_dir,
+    package_test_flit,
+    verbosity: int,
+):
+    monkeypatch.setenv('NO_COLOR', '')
+
+    cmd = [package_test_flit, '-w', '-o', tmp_dir]
+    if verbosity:
+        cmd.insert(0, f'-{"v" * verbosity}')
+
+    build.__main__.main(cmd)
+
+    stdout = capsys.readouterr().out.splitlines()
+    assert sum(1 for o in stdout if o.startswith('> ')) == verbosity
diff --git a/tests/test_projectbuilder.py b/tests/test_projectbuilder.py
index 2017192..77837ea 100644
--- a/tests/test_projectbuilder.py
+++ b/tests/test_projectbuilder.py
@@ -375,6 +375,7 @@ def demo_pkg_inline(tmp_path_factory):
     return next(out.iterdir())
 
 
+@pytest.mark.contextvars
 @pytest.mark.isolated
 def test_build_with_dep_on_console_script(tmp_path, demo_pkg_inline, capfd, mocker):
     """
@@ -549,7 +550,6 @@ def test_log(mocker, caplog, package_test_flit):
     builder.prepare('wheel', '.')
     builder.build('sdist', '.')
     builder.build('wheel', '.')
-    builder.log('something')
 
     assert [(record.levelname, record.message) for record in caplog.records] == [
         ('INFO', 'Getting build dependencies for sdist...'),
@@ -557,7 +557,6 @@ def test_log(mocker, caplog, package_test_flit):
         ('INFO', 'Getting metadata for wheel...'),
         ('INFO', 'Building sdist...'),
         ('INFO', 'Building wheel...'),
-        ('INFO', 'something'),
     ]
 
 
diff --git a/tests/test_self_packaging.py b/tests/test_self_packaging.py
index 9cdcc07..b458936 100644
--- a/tests/test_self_packaging.py
+++ b/tests/test_self_packaging.py
@@ -52,6 +52,7 @@ wheel_files = {
     'build/_compat/importlib.py',
     'build/_compat/tarfile.py',
     'build/_compat/tomllib.py',
+    'build/_ctx.py',
     'build/_exceptions.py',
     'build/_types.py',
     'build/_util.py',