From 03a87c22de1d130cc6564421c7a4a0ddf861da05 Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Fri, 12 Nov 2021 13:19:45 +0000 Subject: [PATCH 01/10] Improve DiagnosticPipError presentation Borrow error presentation logic from sphinx-theme-builder, and exhaustively test both the unicode and non-unicode presentation. Utilise rich for colours and presentation logic handling, with tests to ensure that colour degradation happens cleanly, and that the content is stylized exactly as expected. Catch diagnostic errors eagerly, and present them using rich. While this won't include the pretty presentation in user logs, those files will contain the entire traceback upto that line. --- src/pip/_internal/cli/base_command.py | 12 +- src/pip/_internal/exceptions.py | 133 +++++++++--- tests/unit/test_exceptions.py | 293 ++++++++++++++++++++++++-- 3 files changed, 384 insertions(+), 54 deletions(-) diff --git a/src/pip/_internal/cli/base_command.py b/src/pip/_internal/cli/base_command.py index 5c41488ce3c..c3526d3a4f7 100644 --- a/src/pip/_internal/cli/base_command.py +++ b/src/pip/_internal/cli/base_command.py @@ -10,6 +10,8 @@ from optparse import Values from typing import Any, Callable, List, Optional, Tuple +from pip._vendor import rich + from pip._internal.cli import cmdoptions from pip._internal.cli.command_context import CommandContextMixIn from pip._internal.cli.parser import ConfigOptionParser, UpdatingDefaultsHelpFormatter @@ -165,16 +167,16 @@ def exc_logging_wrapper(*args: Any) -> int: status = run_func(*args) assert isinstance(status, int) return status - except PreviousBuildDirError as exc: - logger.critical(str(exc)) + except DiagnosticPipError as exc: + rich.print(exc, file=sys.stderr) logger.debug("Exception information:", exc_info=True) - return PREVIOUS_BUILD_DIR_ERROR - except DiagnosticPipError as exc: + return ERROR + except PreviousBuildDirError as exc: logger.critical(str(exc)) logger.debug("Exception information:", exc_info=True) - return ERROR + return PREVIOUS_BUILD_DIR_ERROR except ( InstallationError, UninstallationError, diff --git a/src/pip/_internal/exceptions.py b/src/pip/_internal/exceptions.py index 8a17996892f..c20850becde 100644 --- a/src/pip/_internal/exceptions.py +++ b/src/pip/_internal/exceptions.py @@ -3,9 +3,11 @@ import configparser import re from itertools import chain, groupby, repeat -from typing import TYPE_CHECKING, Dict, Iterator, List, Optional +from typing import TYPE_CHECKING, Dict, List, Optional, Union from pip._vendor.requests.models import Request, Response +from pip._vendor.rich.console import Console, ConsoleOptions, RenderResult +from pip._vendor.rich.text import Text if TYPE_CHECKING: from hashlib import _Hash @@ -22,13 +24,21 @@ def _is_kebab_case(s: str) -> bool: return re.match(r"^[a-z]+(-[a-z]+)*$", s) is not None -def _prefix_with_indent(prefix: str, s: str, indent: Optional[str] = None) -> str: - if indent is None: - indent = " " * len(prefix) +def _prefix_with_indent( + s: Union[Text, str], + console: Console, + *, + prefix: str, + indent: str, +) -> Text: + if isinstance(s, Text): + text = s else: - assert len(indent) == len(prefix) - message = s.replace("\n", "\n" + indent) - return f"{prefix}{message}\n" + text = console.render_str(s) + + lines = text.wrap(console, console.width - width_offset) + + return console.render_str(prefix) + console.render_str(f"\n{indent}").join(lines) class PipError(Exception): @@ -36,12 +46,14 @@ class PipError(Exception): class DiagnosticPipError(PipError): - """A pip error, that presents diagnostic information to the user. + """An error, that presents diagnostic information to the user. This contains a bunch of logic, to enable pretty presentation of our error messages. Each error gets a unique reference. Each error can also include additional context, a hint and/or a note -- which are presented with the main error message in a consistent style. + + This is adapted from the error output styling in `sphinx-theme-builder`. """ reference: str @@ -49,48 +61,103 @@ class DiagnosticPipError(PipError): def __init__( self, *, - message: str, - context: Optional[str], - hint_stmt: Optional[str], - attention_stmt: Optional[str] = None, - reference: Optional[str] = None, kind: 'Literal["error", "warning"]' = "error", + reference: Optional[str] = None, + message: Union[str, Text], + context: Optional[Union[str, Text]], + hint_stmt: Optional[Union[str, Text]], + attention_stmt: Optional[Union[str, Text]] = None, + link: Optional[str] = None, ) -> None: - # Ensure a proper reference is provided. if reference is None: assert hasattr(self, "reference"), "error reference not provided!" reference = self.reference assert _is_kebab_case(reference), "error reference must be kebab-case!" - super().__init__(f"{reference}: {message}") - self.kind = kind + self.reference = reference + self.message = message self.context = context - self.reference = reference self.attention_stmt = attention_stmt self.hint_stmt = hint_stmt - def __str__(self) -> str: - return "".join(self._string_parts()) + self.link = link - def _string_parts(self) -> Iterator[str]: - # Present the main message, with relevant context indented. - yield f"{self.message}\n" - if self.context is not None: - yield f"\n{self.context}\n" + super().__init__(f"<{self.__class__.__name__}: {self.reference}>") + + def __repr__(self) -> str: + return ( + f"<{self.__class__.__name__}(" + f"reference={self.reference!r}, " + f"message={self.message!r}, " + f"context={self.context!r}, " + f"attention_stmt={self.attention_stmt!r}, " + f"hint_stmt={self.hint_stmt!r}" + ")>" + ) + + def __rich_console__( + self, + console: Console, + options: ConsoleOptions, + ) -> RenderResult: + colour = "red" if self.kind == "error" else "yellow" + + yield f"[{colour} bold]{self.kind}[/]: [bold]{self.reference}[/]" + yield "" + + if not options.ascii_only: + # Present the main message, with relevant context indented. + if self.context is not None: + yield _prefix_with_indent( + self.message, + console, + prefix=f"[{colour}]×[/] ", + indent=f"[{colour}]│[/] ", + ) + yield _prefix_with_indent( + self.context, + console, + prefix=f"[{colour}]╰─>[/] ", + indent=f"[{colour}] [/] ", + ) + else: + yield _prefix_with_indent( + self.message, + console, + prefix="[red]×[/] ", + indent=" ", + ) + else: + yield self.message + if self.context is not None: + yield "" + yield self.context - # Space out the note/hint messages. if self.attention_stmt is not None or self.hint_stmt is not None: - yield "\n" + yield "" if self.attention_stmt is not None: - yield _prefix_with_indent("Note: ", self.attention_stmt) - + yield _prefix_with_indent( + self.attention_stmt, + console, + prefix="[magenta bold]note[/]: ", + indent=" ", + ) if self.hint_stmt is not None: - yield _prefix_with_indent("Hint: ", self.hint_stmt) + yield _prefix_with_indent( + self.hint_stmt, + console, + prefix="[cyan bold]hint[/]: ", + indent=" ", + ) + + if self.link is not None: + yield "" + yield f"Link: {self.link}" # @@ -118,12 +185,12 @@ def __init__(self, *, package: str) -> None: message=f"Can not process {package}", context=( "This package has an invalid pyproject.toml file.\n" - "The [build-system] table is missing the mandatory `requires` key." + R"The \[build-system] table is missing the mandatory `requires` key." ), attention_stmt=( "This is an issue with the package mentioned above, not pip." ), - hint_stmt="See PEP 518 for the detailed specification.", + hint_stmt=Text("See PEP 518 for the detailed specification."), ) @@ -135,12 +202,12 @@ class InvalidPyProjectBuildRequires(DiagnosticPipError): def __init__(self, *, package: str, reason: str) -> None: super().__init__( message=f"Can not process {package}", - context=( + context=Text( "This package has an invalid `build-system.requires` key in " "pyproject.toml.\n" f"{reason}" ), - hint_stmt="See PEP 518 for the detailed specification.", + hint_stmt=Text("See PEP 518 for the detailed specification."), attention_stmt=( "This is an issue with the package mentioned above, not pip." ), diff --git a/tests/unit/test_exceptions.py b/tests/unit/test_exceptions.py index 45e6bee10da..84e512578d5 100644 --- a/tests/unit/test_exceptions.py +++ b/tests/unit/test_exceptions.py @@ -1,8 +1,10 @@ """Tests the presentation style of exceptions.""" +import io import textwrap import pytest +from pip._vendor import rich from pip._internal.exceptions import DiagnosticPipError @@ -57,6 +59,17 @@ class DerivedError(DiagnosticPipError): assert str(exc_info.value) == "error reference must be kebab-case!" +def rendered_in_ascii(error: DiagnosticPipError, *, color: bool = False) -> str: + with io.BytesIO() as stream: + console = rich.console.Console( + force_terminal=False, + file=io.TextIOWrapper(stream, encoding="ascii"), + color_system="truecolor" if color else None, + ) + console.print(error) + return stream.getvalue().decode("ascii") + + class TestDiagnosticPipErrorPresentation_ASCII: def test_complete(self) -> None: err = DiagnosticPipError( @@ -67,16 +80,45 @@ def test_complete(self) -> None: hint_stmt="Do it better next time, by trying harder.", ) - assert str(err) == textwrap.dedent( + assert rendered_in_ascii(err) == textwrap.dedent( """\ + error: test-diagnostic + Oh no! It broke. :( Something went wrong very wrong. - Note: You did something wrong, which is what caused this error. - Hint: Do it better next time, by trying harder. + note: You did something wrong, which is what caused this error. + hint: Do it better next time, by trying harder. + """ + ) + + def test_complete_color(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke.", + context="Something went wrong\nvery wrong.", + attention_stmt="You did something wrong.", + hint_stmt="Do it better next time, by trying harder.", + ) + + def esc(code: str = "0") -> str: + return f"\x1b[{code}m" + + assert rendered_in_ascii(err, color=True) == textwrap.dedent( + f"""\ + {esc("1;31")}error{esc("0")}: {esc("1")}test-diagnostic{esc("0")} + + Oh no! + It broke. + + Something went wrong + very wrong. + + {esc("1;35")}note{esc("0")}: You did something wrong. + {esc("1;36")}hint{esc("0")}: Do it better next time, by trying harder. """ ) @@ -89,13 +131,15 @@ def test_no_context(self) -> None: hint_stmt="Do it better next time, by trying harder.", ) - assert str(err) == textwrap.dedent( + assert rendered_in_ascii(err) == textwrap.dedent( """\ + error: test-diagnostic + Oh no! It broke. :( - Note: You did something wrong, which is what caused this error. - Hint: Do it better next time, by trying harder. + note: You did something wrong, which is what caused this error. + hint: Do it better next time, by trying harder. """ ) @@ -108,15 +152,17 @@ def test_no_note(self) -> None: hint_stmt="Do it better next time, by trying harder.", ) - assert str(err) == textwrap.dedent( + assert rendered_in_ascii(err) == textwrap.dedent( """\ + error: test-diagnostic + Oh no! It broke. :( Something went wrong very wrong. - Hint: Do it better next time, by trying harder. + hint: Do it better next time, by trying harder. """ ) @@ -129,15 +175,17 @@ def test_no_hint(self) -> None: hint_stmt=None, ) - assert str(err) == textwrap.dedent( + assert rendered_in_ascii(err) == textwrap.dedent( """\ + error: test-diagnostic + Oh no! It broke. :( Something went wrong very wrong. - Note: You did something wrong, which is what caused this error. + note: You did something wrong, which is what caused this error. """ ) @@ -150,12 +198,14 @@ def test_no_context_no_hint(self) -> None: hint_stmt=None, ) - assert str(err) == textwrap.dedent( + assert rendered_in_ascii(err) == textwrap.dedent( """\ + error: test-diagnostic + Oh no! It broke. :( - Note: You did something wrong, which is what caused this error. + note: You did something wrong, which is what caused this error. """ ) @@ -168,12 +218,14 @@ def test_no_context_no_note(self) -> None: hint_stmt="Do it better next time, by trying harder.", ) - assert str(err) == textwrap.dedent( + assert rendered_in_ascii(err) == textwrap.dedent( """\ + error: test-diagnostic + Oh no! It broke. :( - Hint: Do it better next time, by trying harder. + hint: Do it better next time, by trying harder. """ ) @@ -186,8 +238,10 @@ def test_no_hint_no_note(self) -> None: hint_stmt=None, ) - assert str(err) == textwrap.dedent( + assert rendered_in_ascii(err) == textwrap.dedent( """\ + error: test-diagnostic + Oh no! It broke. :( @@ -205,9 +259,216 @@ def test_no_hint_no_note_no_context(self) -> None: attention_stmt=None, ) - assert str(err) == textwrap.dedent( + assert rendered_in_ascii(err) == textwrap.dedent( """\ + error: test-diagnostic + Oh no! It broke. :( """ ) + + +def rendered(error: DiagnosticPipError, *, color: bool = False) -> str: + with io.StringIO() as stream: + console = rich.console.Console( + force_terminal=False, + file=stream, + color_system="truecolor" if color else None, + ) + console.print(error) + return stream.getvalue() + + +class TestDiagnosticPipErrorPresentation_Unicode: + def test_complete(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke. :(", + context="Something went wrong\nvery wrong.", + attention_stmt="You did something wrong, which is what caused this error.", + hint_stmt="Do it better next time, by trying harder.", + ) + + assert rendered(err) == textwrap.dedent( + """\ + error: test-diagnostic + + × Oh no! + │ It broke. :( + ╰─> Something went wrong + very wrong. + + note: You did something wrong, which is what caused this error. + hint: Do it better next time, by trying harder. + """ + ) + + def test_complete_color(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke.", + context="Something went wrong\nvery wrong.", + attention_stmt="You did something wrong.", + hint_stmt="Do it better next time, by trying harder.", + ) + + def esc(code: str = "0") -> str: + return f"\x1b[{code}m" + + assert rendered(err, color=True) == textwrap.dedent( + f"""\ + {esc("1;31")}error{esc("0")}: {esc("1")}test-diagnostic{esc("0")} + + {esc("31")}×{esc("0")} Oh no! + {esc("31")}│{esc("0")} It broke. + {esc("31")}╰─>{esc("0")} Something went wrong + {esc("31")} {esc("0")} very wrong. + + {esc("1;35")}note{esc("0")}: You did something wrong. + {esc("1;36")}hint{esc("0")}: Do it better next time, by trying harder. + """ + ) + + def test_no_context(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke. :(", + context=None, + attention_stmt="You did something wrong, which is what caused this error.", + hint_stmt="Do it better next time, by trying harder.", + ) + + assert rendered(err) == textwrap.dedent( + """\ + error: test-diagnostic + + × Oh no! + It broke. :( + + note: You did something wrong, which is what caused this error. + hint: Do it better next time, by trying harder. + """ + ) + + def test_no_note(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke. :(", + context="Something went wrong\nvery wrong.", + attention_stmt=None, + hint_stmt="Do it better next time, by trying harder.", + ) + + assert rendered(err) == textwrap.dedent( + """\ + error: test-diagnostic + + × Oh no! + │ It broke. :( + ╰─> Something went wrong + very wrong. + + hint: Do it better next time, by trying harder. + """ + ) + + def test_no_hint(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke. :(", + context="Something went wrong\nvery wrong.", + attention_stmt="You did something wrong, which is what caused this error.", + hint_stmt=None, + ) + + assert rendered(err) == textwrap.dedent( + """\ + error: test-diagnostic + + × Oh no! + │ It broke. :( + ╰─> Something went wrong + very wrong. + + note: You did something wrong, which is what caused this error. + """ + ) + + def test_no_context_no_hint(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke. :(", + context=None, + attention_stmt="You did something wrong, which is what caused this error.", + hint_stmt=None, + ) + + assert rendered(err) == textwrap.dedent( + """\ + error: test-diagnostic + + × Oh no! + It broke. :( + + note: You did something wrong, which is what caused this error. + """ + ) + + def test_no_context_no_note(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke. :(", + context=None, + attention_stmt=None, + hint_stmt="Do it better next time, by trying harder.", + ) + + assert rendered(err) == textwrap.dedent( + """\ + error: test-diagnostic + + × Oh no! + It broke. :( + + hint: Do it better next time, by trying harder. + """ + ) + + def test_no_hint_no_note(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke. :(", + context="Something went wrong\nvery wrong.", + attention_stmt=None, + hint_stmt=None, + ) + + assert rendered(err) == textwrap.dedent( + """\ + error: test-diagnostic + + × Oh no! + │ It broke. :( + ╰─> Something went wrong + very wrong. + """ + ) + + def test_no_hint_no_note_no_context(self) -> None: + err = DiagnosticPipError( + reference="test-diagnostic", + message="Oh no!\nIt broke. :(", + context=None, + hint_stmt=None, + attention_stmt=None, + ) + + assert rendered(err) == textwrap.dedent( + """\ + error: test-diagnostic + + × Oh no! + It broke. :( + """ + ) From 8feb24fd12d90436d09d28bf84f90c4abb48f87f Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Sun, 14 Nov 2021 09:35:38 +0000 Subject: [PATCH 02/10] Enable the use of rich for presenting output This makes it possible to present output with rich markup, within the constraints of our logging infrastructure. Further, diagnostic errors can now by presented using rich, using their own special "[present-diagnostic]" marker string, since those need to be handled differently from regular log messages and passed directly through to rich's console object, after an indentation wrapper. --- src/pip/_internal/cli/base_command.py | 4 +- src/pip/_internal/exceptions.py | 6 +- src/pip/_internal/utils/logging.py | 153 +++++++++++--------------- tests/unit/test_logging.py | 8 +- 4 files changed, 73 insertions(+), 98 deletions(-) diff --git a/src/pip/_internal/cli/base_command.py b/src/pip/_internal/cli/base_command.py index c3526d3a4f7..81c443adf49 100644 --- a/src/pip/_internal/cli/base_command.py +++ b/src/pip/_internal/cli/base_command.py @@ -10,8 +10,6 @@ from optparse import Values from typing import Any, Callable, List, Optional, Tuple -from pip._vendor import rich - from pip._internal.cli import cmdoptions from pip._internal.cli.command_context import CommandContextMixIn from pip._internal.cli.parser import ConfigOptionParser, UpdatingDefaultsHelpFormatter @@ -168,7 +166,7 @@ def exc_logging_wrapper(*args: Any) -> int: assert isinstance(status, int) return status except DiagnosticPipError as exc: - rich.print(exc, file=sys.stderr) + logger.error("[present-diagnostic]", exc) logger.debug("Exception information:", exc_info=True) return ERROR diff --git a/src/pip/_internal/exceptions.py b/src/pip/_internal/exceptions.py index c20850becde..08589718d36 100644 --- a/src/pip/_internal/exceptions.py +++ b/src/pip/_internal/exceptions.py @@ -36,9 +36,9 @@ def _prefix_with_indent( else: text = console.render_str(s) - lines = text.wrap(console, console.width - width_offset) - - return console.render_str(prefix) + console.render_str(f"\n{indent}").join(lines) + return console.render_str(prefix, overflow="ignore") + console.render_str( + f"\n{indent}", overflow="ignore" + ).join(text.split(allow_blank=True)) class PipError(Exception): diff --git a/src/pip/_internal/utils/logging.py b/src/pip/_internal/utils/logging.py index a4b828a84e1..8a71535dc01 100644 --- a/src/pip/_internal/utils/logging.py +++ b/src/pip/_internal/utils/logging.py @@ -4,28 +4,27 @@ import logging.handlers import os import sys +import threading +from dataclasses import dataclass from logging import Filter -from typing import IO, Any, Callable, Iterator, Optional, TextIO, Type, cast - +from typing import IO, Any, ClassVar, Iterator, List, Optional, TextIO, Type + +from pip._vendor.rich.console import ( + Console, + ConsoleOptions, + ConsoleRenderable, + RenderResult, +) +from pip._vendor.rich.highlighter import NullHighlighter +from pip._vendor.rich.logging import RichHandler +from pip._vendor.rich.segment import Segment + +from pip._internal.exceptions import DiagnosticPipError from pip._internal.utils._log import VERBOSE, getLogger from pip._internal.utils.compat import WINDOWS from pip._internal.utils.deprecation import DEPRECATION_MSG_PREFIX from pip._internal.utils.misc import ensure_dir -try: - import threading -except ImportError: - import dummy_threading as threading # type: ignore - - -try: - from pip._vendor import colorama -# Lots of different errors can come from this, including SystemError and -# ImportError. -except Exception: - colorama = None - - _log_state = threading.local() subprocess_logger = getLogger("pip.subprocessor") @@ -119,78 +118,56 @@ def format(self, record: logging.LogRecord) -> str: return formatted -def _color_wrap(*colors: str) -> Callable[[str], str]: - def wrapped(inp: str) -> str: - return "".join(list(colors) + [inp, colorama.Style.RESET_ALL]) - - return wrapped - - -class ColorizedStreamHandler(logging.StreamHandler): - - # Don't build up a list of colors if we don't have colorama - if colorama: - COLORS = [ - # This needs to be in order from highest logging level to lowest. - (logging.ERROR, _color_wrap(colorama.Fore.RED)), - (logging.WARNING, _color_wrap(colorama.Fore.YELLOW)), - ] - else: - COLORS = [] - - def __init__(self, stream: Optional[TextIO] = None, no_color: bool = None) -> None: - super().__init__(stream) - self._no_color = no_color - - if WINDOWS and colorama: - self.stream = colorama.AnsiToWin32(self.stream) - - def _using_stdout(self) -> bool: - """ - Return whether the handler is using sys.stdout. - """ - if WINDOWS and colorama: - # Then self.stream is an AnsiToWin32 object. - stream = cast(colorama.AnsiToWin32, self.stream) - return stream.wrapped is sys.stdout - - return self.stream is sys.stdout - - def should_color(self) -> bool: - # Don't colorize things if we do not have colorama or if told not to - if not colorama or self._no_color: - return False - - real_stream = ( - self.stream - if not isinstance(self.stream, colorama.AnsiToWin32) - else self.stream.wrapped +@dataclass +class IndentedRenderable: + renderable: ConsoleRenderable + indent: int + + def __rich_console__( + self, console: Console, options: ConsoleOptions + ) -> RenderResult: + segments = console.render(self.renderable, options) + lines = Segment.split_lines(segments) + for line in lines: + yield Segment(" " * self.indent) + yield from line + yield Segment("\n") + + +class RichPipStreamHandler(RichHandler): + KEYWORDS: ClassVar[Optional[List[str]]] = [] + + def __init__(self, stream: Optional[TextIO], no_color: bool) -> None: + super().__init__( + console=Console(file=stream, no_color=no_color, soft_wrap=True), + show_time=False, + show_level=False, + show_path=False, + highlighter=NullHighlighter(), ) - # If the stream is a tty we should color it - if hasattr(real_stream, "isatty") and real_stream.isatty(): - return True - - # If we have an ANSI term we should color it - if os.environ.get("TERM") == "ANSI": - return True - - # If anything else we should not color it - return False - - def format(self, record: logging.LogRecord) -> str: - msg = super().format(record) - - if self.should_color(): - for level, color in self.COLORS: - if record.levelno >= level: - msg = color(msg) - break - - return msg + # Our custom override on rich's logger, to make things work as we need them to. + def emit(self, record: logging.LogRecord) -> None: + # If we are given a diagnostic error to present, present it with indentation. + if record.msg == "[present-diagnostic]" and len(record.args) == 1: + diagnostic_error: DiagnosticPipError = record.args[0] # type: ignore[index] + assert isinstance(diagnostic_error, DiagnosticPipError) + + renderable: ConsoleRenderable = IndentedRenderable( + diagnostic_error, indent=get_indentation() + ) + else: + message = self.format(record) + renderable = self.render_message(record, message) + + try: + self.console.print(renderable, overflow="ignore", crop=False) + except Exception: + self.handleError(record) - # The logging module says handleError() can be customized. def handleError(self, record: logging.LogRecord) -> None: + """Called when logging is unable to log some output.""" + exc_class, exc = sys.exc_info()[:2] # If a broken pipe occurred while calling write() or flush() on the # stdout stream in logging's Handler.emit(), then raise our special @@ -199,7 +176,7 @@ def handleError(self, record: logging.LogRecord) -> None: if ( exc_class and exc - and self._using_stdout() + and self.console.file is sys.stdout and _is_broken_pipe_error(exc_class, exc) ): raise BrokenStdoutLoggingError() @@ -275,7 +252,8 @@ def setup_logging(verbosity: int, no_color: bool, user_log_file: Optional[str]) "stderr": "ext://sys.stderr", } handler_classes = { - "stream": "pip._internal.utils.logging.ColorizedStreamHandler", + "subprocess": "logging.StreamHandler", + "stream": "pip._internal.utils.logging.RichPipStreamHandler", "file": "pip._internal.utils.logging.BetterRotatingFileHandler", } handlers = ["console", "console_errors", "console_subprocess"] + ( @@ -332,8 +310,7 @@ def setup_logging(verbosity: int, no_color: bool, user_log_file: Optional[str]) # from the "subprocessor" logger. "console_subprocess": { "level": level, - "class": handler_classes["stream"], - "no_color": no_color, + "class": handler_classes["subprocess"], "stream": log_streams["stderr"], "filters": ["restrict_to_subprocess"], "formatter": "indent", diff --git a/tests/unit/test_logging.py b/tests/unit/test_logging.py index 7b90d5dcc70..4f0447931dd 100644 --- a/tests/unit/test_logging.py +++ b/tests/unit/test_logging.py @@ -6,8 +6,8 @@ from pip._internal.utils.logging import ( BrokenStdoutLoggingError, - ColorizedStreamHandler, IndentingFormatter, + RichPipStreamHandler, indent_log, ) from pip._internal.utils.misc import captured_stderr, captured_stdout @@ -142,7 +142,7 @@ def test_broken_pipe_in_stderr_flush(self) -> None: record = self._make_log_record() with captured_stderr() as stderr: - handler = ColorizedStreamHandler(stream=stderr) + handler = RichPipStreamHandler(stream=stderr, no_color=True) with patch("sys.stderr.flush") as mock_flush: mock_flush.side_effect = BrokenPipeError() # The emit() call raises no exception. @@ -165,7 +165,7 @@ def test_broken_pipe_in_stdout_write(self) -> None: record = self._make_log_record() with captured_stdout() as stdout: - handler = ColorizedStreamHandler(stream=stdout) + handler = RichPipStreamHandler(stream=stdout, no_color=True) with patch("sys.stdout.write") as mock_write: mock_write.side_effect = BrokenPipeError() with pytest.raises(BrokenStdoutLoggingError): @@ -180,7 +180,7 @@ def test_broken_pipe_in_stdout_flush(self) -> None: record = self._make_log_record() with captured_stdout() as stdout: - handler = ColorizedStreamHandler(stream=stdout) + handler = RichPipStreamHandler(stream=stdout, no_color=True) with patch("sys.stdout.flush") as mock_flush: mock_flush.side_effect = BrokenPipeError() with pytest.raises(BrokenStdoutLoggingError): From 9f4117f2b8a4107c931b8ed74c42571a48f164c2 Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Fri, 3 Dec 2021 14:22:18 +0000 Subject: [PATCH 03/10] Replace {attention -> note}_stmt The new name is a closer match with what is presented to the user. --- src/pip/_internal/exceptions.py | 20 ++++++++---------- tests/unit/test_exceptions.py | 36 ++++++++++++++++----------------- 2 files changed, 26 insertions(+), 30 deletions(-) diff --git a/src/pip/_internal/exceptions.py b/src/pip/_internal/exceptions.py index 08589718d36..08cbadbbf48 100644 --- a/src/pip/_internal/exceptions.py +++ b/src/pip/_internal/exceptions.py @@ -66,7 +66,7 @@ def __init__( message: Union[str, Text], context: Optional[Union[str, Text]], hint_stmt: Optional[Union[str, Text]], - attention_stmt: Optional[Union[str, Text]] = None, + note_stmt: Optional[Union[str, Text]] = None, link: Optional[str] = None, ) -> None: # Ensure a proper reference is provided. @@ -81,7 +81,7 @@ def __init__( self.message = message self.context = context - self.attention_stmt = attention_stmt + self.note_stmt = note_stmt self.hint_stmt = hint_stmt self.link = link @@ -94,7 +94,7 @@ def __repr__(self) -> str: f"reference={self.reference!r}, " f"message={self.message!r}, " f"context={self.context!r}, " - f"attention_stmt={self.attention_stmt!r}, " + f"note_stmt={self.note_stmt!r}, " f"hint_stmt={self.hint_stmt!r}" ")>" ) @@ -137,12 +137,12 @@ def __rich_console__( yield "" yield self.context - if self.attention_stmt is not None or self.hint_stmt is not None: + if self.note_stmt is not None or self.hint_stmt is not None: yield "" - if self.attention_stmt is not None: + if self.note_stmt is not None: yield _prefix_with_indent( - self.attention_stmt, + self.note_stmt, console, prefix="[magenta bold]note[/]: ", indent=" ", @@ -187,9 +187,7 @@ def __init__(self, *, package: str) -> None: "This package has an invalid pyproject.toml file.\n" R"The \[build-system] table is missing the mandatory `requires` key." ), - attention_stmt=( - "This is an issue with the package mentioned above, not pip." - ), + note_stmt="This is an issue with the package mentioned above, not pip.", hint_stmt=Text("See PEP 518 for the detailed specification."), ) @@ -207,10 +205,8 @@ def __init__(self, *, package: str, reason: str) -> None: "pyproject.toml.\n" f"{reason}" ), + note_stmt="This is an issue with the package mentioned above, not pip.", hint_stmt=Text("See PEP 518 for the detailed specification."), - attention_stmt=( - "This is an issue with the package mentioned above, not pip." - ), ) diff --git a/tests/unit/test_exceptions.py b/tests/unit/test_exceptions.py index 84e512578d5..e3bf8fb4bae 100644 --- a/tests/unit/test_exceptions.py +++ b/tests/unit/test_exceptions.py @@ -76,7 +76,7 @@ def test_complete(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context="Something went wrong\nvery wrong.", - attention_stmt="You did something wrong, which is what caused this error.", + note_stmt="You did something wrong, which is what caused this error.", hint_stmt="Do it better next time, by trying harder.", ) @@ -100,7 +100,7 @@ def test_complete_color(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke.", context="Something went wrong\nvery wrong.", - attention_stmt="You did something wrong.", + note_stmt="You did something wrong.", hint_stmt="Do it better next time, by trying harder.", ) @@ -127,7 +127,7 @@ def test_no_context(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context=None, - attention_stmt="You did something wrong, which is what caused this error.", + note_stmt="You did something wrong, which is what caused this error.", hint_stmt="Do it better next time, by trying harder.", ) @@ -148,7 +148,7 @@ def test_no_note(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context="Something went wrong\nvery wrong.", - attention_stmt=None, + note_stmt=None, hint_stmt="Do it better next time, by trying harder.", ) @@ -171,7 +171,7 @@ def test_no_hint(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context="Something went wrong\nvery wrong.", - attention_stmt="You did something wrong, which is what caused this error.", + note_stmt="You did something wrong, which is what caused this error.", hint_stmt=None, ) @@ -194,7 +194,7 @@ def test_no_context_no_hint(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context=None, - attention_stmt="You did something wrong, which is what caused this error.", + note_stmt="You did something wrong, which is what caused this error.", hint_stmt=None, ) @@ -214,7 +214,7 @@ def test_no_context_no_note(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context=None, - attention_stmt=None, + note_stmt=None, hint_stmt="Do it better next time, by trying harder.", ) @@ -234,7 +234,7 @@ def test_no_hint_no_note(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context="Something went wrong\nvery wrong.", - attention_stmt=None, + note_stmt=None, hint_stmt=None, ) @@ -256,7 +256,7 @@ def test_no_hint_no_note_no_context(self) -> None: message="Oh no!\nIt broke. :(", context=None, hint_stmt=None, - attention_stmt=None, + note_stmt=None, ) assert rendered_in_ascii(err) == textwrap.dedent( @@ -286,7 +286,7 @@ def test_complete(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context="Something went wrong\nvery wrong.", - attention_stmt="You did something wrong, which is what caused this error.", + note_stmt="You did something wrong, which is what caused this error.", hint_stmt="Do it better next time, by trying harder.", ) @@ -309,7 +309,7 @@ def test_complete_color(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke.", context="Something went wrong\nvery wrong.", - attention_stmt="You did something wrong.", + note_stmt="You did something wrong.", hint_stmt="Do it better next time, by trying harder.", ) @@ -335,7 +335,7 @@ def test_no_context(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context=None, - attention_stmt="You did something wrong, which is what caused this error.", + note_stmt="You did something wrong, which is what caused this error.", hint_stmt="Do it better next time, by trying harder.", ) @@ -356,7 +356,7 @@ def test_no_note(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context="Something went wrong\nvery wrong.", - attention_stmt=None, + note_stmt=None, hint_stmt="Do it better next time, by trying harder.", ) @@ -378,7 +378,7 @@ def test_no_hint(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context="Something went wrong\nvery wrong.", - attention_stmt="You did something wrong, which is what caused this error.", + note_stmt="You did something wrong, which is what caused this error.", hint_stmt=None, ) @@ -400,7 +400,7 @@ def test_no_context_no_hint(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context=None, - attention_stmt="You did something wrong, which is what caused this error.", + note_stmt="You did something wrong, which is what caused this error.", hint_stmt=None, ) @@ -420,7 +420,7 @@ def test_no_context_no_note(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context=None, - attention_stmt=None, + note_stmt=None, hint_stmt="Do it better next time, by trying harder.", ) @@ -440,7 +440,7 @@ def test_no_hint_no_note(self) -> None: reference="test-diagnostic", message="Oh no!\nIt broke. :(", context="Something went wrong\nvery wrong.", - attention_stmt=None, + note_stmt=None, hint_stmt=None, ) @@ -461,7 +461,7 @@ def test_no_hint_no_note_no_context(self) -> None: message="Oh no!\nIt broke. :(", context=None, hint_stmt=None, - attention_stmt=None, + note_stmt=None, ) assert rendered(err) == textwrap.dedent( From d517dae1b7298839de577063f810cdb71b62ac84 Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Fri, 3 Dec 2021 14:28:58 +0000 Subject: [PATCH 04/10] Clean up where `Text` is used to wrap diagnostic messages. This is only necessary on messages which may contain `[`, which needs to be escaped before printing with rich, since rich treats them as output formats. --- src/pip/_internal/exceptions.py | 15 +++++++-------- 1 file changed, 7 insertions(+), 8 deletions(-) diff --git a/src/pip/_internal/exceptions.py b/src/pip/_internal/exceptions.py index 08cbadbbf48..394ac6b1cca 100644 --- a/src/pip/_internal/exceptions.py +++ b/src/pip/_internal/exceptions.py @@ -182,13 +182,13 @@ class MissingPyProjectBuildRequires(DiagnosticPipError): def __init__(self, *, package: str) -> None: super().__init__( - message=f"Can not process {package}", - context=( + message=Text(f"Can not process {package}"), + context=Text( "This package has an invalid pyproject.toml file.\n" - R"The \[build-system] table is missing the mandatory `requires` key." + "The [build-system] table is missing the mandatory `requires` key." ), note_stmt="This is an issue with the package mentioned above, not pip.", - hint_stmt=Text("See PEP 518 for the detailed specification."), + hint_stmt="See PEP 518 for the detailed specification.", ) @@ -199,14 +199,13 @@ class InvalidPyProjectBuildRequires(DiagnosticPipError): def __init__(self, *, package: str, reason: str) -> None: super().__init__( - message=f"Can not process {package}", + message=Text(f"Can not process {package}"), context=Text( "This package has an invalid `build-system.requires` key in " - "pyproject.toml.\n" - f"{reason}" + f"pyproject.toml.\n{reason}" ), note_stmt="This is an issue with the package mentioned above, not pip.", - hint_stmt=Text("See PEP 518 for the detailed specification."), + hint_stmt="See PEP 518 for the detailed specification.", ) From 6a20f5b05676f9c685e34ae1e0ac6e301e2d1752 Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Fri, 3 Dec 2021 15:01:31 +0000 Subject: [PATCH 05/10] Add news fragment --- news/10703.feature.rst | 1 + 1 file changed, 1 insertion(+) create mode 100644 news/10703.feature.rst diff --git a/news/10703.feature.rst b/news/10703.feature.rst new file mode 100644 index 00000000000..39812e6bed6 --- /dev/null +++ b/news/10703.feature.rst @@ -0,0 +1 @@ +Start utilising ``rich`` for presenting error messages in a consistent format. From e857d0f532a5745d9c76b927559915926b20a7cc Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Fri, 3 Dec 2021 15:06:44 +0000 Subject: [PATCH 06/10] Properly handle newlines in diagnostic error tests This is necessary to ensure that the output can be compared directly. --- tests/unit/test_exceptions.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/unit/test_exceptions.py b/tests/unit/test_exceptions.py index e3bf8fb4bae..8f8224dc817 100644 --- a/tests/unit/test_exceptions.py +++ b/tests/unit/test_exceptions.py @@ -63,7 +63,7 @@ def rendered_in_ascii(error: DiagnosticPipError, *, color: bool = False) -> str: with io.BytesIO() as stream: console = rich.console.Console( force_terminal=False, - file=io.TextIOWrapper(stream, encoding="ascii"), + file=io.TextIOWrapper(stream, encoding="ascii", newline=""), color_system="truecolor" if color else None, ) console.print(error) From b82dfd174591f58868e29f8838d18f371632dba5 Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Sat, 4 Dec 2021 18:47:54 +0000 Subject: [PATCH 07/10] Restore colors in regular logging messages Also, reflects that `--no-color` does not mean no-ansi-escapes but only affects colour rules. --- src/pip/_internal/utils/logging.py | 14 +++++++++++--- tests/functional/test_no_color.py | 22 +++++++++++----------- 2 files changed, 22 insertions(+), 14 deletions(-) diff --git a/src/pip/_internal/utils/logging.py b/src/pip/_internal/utils/logging.py index 8a71535dc01..0d505dc87bf 100644 --- a/src/pip/_internal/utils/logging.py +++ b/src/pip/_internal/utils/logging.py @@ -18,6 +18,7 @@ from pip._vendor.rich.highlighter import NullHighlighter from pip._vendor.rich.logging import RichHandler from pip._vendor.rich.segment import Segment +from pip._vendor.rich.style import Style from pip._internal.exceptions import DiagnosticPipError from pip._internal.utils._log import VERBOSE, getLogger @@ -148,6 +149,8 @@ def __init__(self, stream: Optional[TextIO], no_color: bool) -> None: # Our custom override on rich's logger, to make things work as we need them to. def emit(self, record: logging.LogRecord) -> None: + style: Optional[Style] = None + # If we are given a diagnostic error to present, present it with indentation. if record.msg == "[present-diagnostic]" and len(record.args) == 1: diagnostic_error: DiagnosticPipError = record.args[0] # type: ignore[index] @@ -159,9 +162,14 @@ def emit(self, record: logging.LogRecord) -> None: else: message = self.format(record) renderable = self.render_message(record, message) + if record.levelno is not None: + if record.levelno >= logging.ERROR: + style = Style(color="red") + elif record.levelno >= logging.WARNING: + style = Style(color="yellow") try: - self.console.print(renderable, overflow="ignore", crop=False) + self.console.print(renderable, overflow="ignore", crop=False, style=style) except Exception: self.handleError(record) @@ -252,7 +260,6 @@ def setup_logging(verbosity: int, no_color: bool, user_log_file: Optional[str]) "stderr": "ext://sys.stderr", } handler_classes = { - "subprocess": "logging.StreamHandler", "stream": "pip._internal.utils.logging.RichPipStreamHandler", "file": "pip._internal.utils.logging.BetterRotatingFileHandler", } @@ -310,8 +317,9 @@ def setup_logging(verbosity: int, no_color: bool, user_log_file: Optional[str]) # from the "subprocessor" logger. "console_subprocess": { "level": level, - "class": handler_classes["subprocess"], + "class": handler_classes["stream"], "stream": log_streams["stderr"], + "no_color": no_color, "filters": ["restrict_to_subprocess"], "formatter": "indent", }, diff --git a/tests/functional/test_no_color.py b/tests/functional/test_no_color.py index 9ead9996ad8..4094bdd167a 100644 --- a/tests/functional/test_no_color.py +++ b/tests/functional/test_no_color.py @@ -2,13 +2,16 @@ Test specific for the --no-color option """ import os +import shutil import subprocess +import sys import pytest from tests.lib import PipTestEnvironment +@pytest.mark.skipif(shutil.which("script") is None, reason="no 'script' executable") def test_no_color(script: PipTestEnvironment) -> None: """Ensure colour output disabled when --no-color is passed.""" # Using 'script' in this test allows for transparently testing pip's output @@ -19,12 +22,13 @@ def test_no_color(script: PipTestEnvironment) -> None: # 'script' and well as the mere use of the same. # # This test will stay until someone has the time to rewrite it. - command = ( - "script --flush --quiet --return /tmp/pip-test-no-color.txt " - '--command "pip uninstall {} noSuchPackage"' - ) + pip_command = "pip uninstall {} noSuchPackage" + if sys.platform == "darwin": + command = f"script -q /tmp/pip-test-no-color.txt {pip_command}" + else: + command = f'script -q /tmp/pip-test-no-color.txt --command "{pip_command}"' - def get_run_output(option: str) -> str: + def get_run_output(option: str = "") -> str: cmd = command.format(option) proc = subprocess.Popen( cmd, @@ -33,8 +37,6 @@ def get_run_output(option: str) -> str: stderr=subprocess.PIPE, ) proc.communicate() - if proc.returncode: - pytest.skip("Unable to capture output using script: " + cmd) try: with open("/tmp/pip-test-no-color.txt") as output_file: @@ -43,7 +45,5 @@ def get_run_output(option: str) -> str: finally: os.unlink("/tmp/pip-test-no-color.txt") - assert "\x1b" in get_run_output(option=""), "Expected color in output" - assert "\x1b" not in get_run_output( - option="--no-color" - ), "Expected no color in output" + assert "\x1b[3" in get_run_output(""), "Expected color in output" + assert "\x1b[3" not in get_run_output("--no-color"), "Expected no color in output" From 961eb6f1668fb17025da0d43bd55ce56b25e2374 Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Sun, 12 Dec 2021 13:10:05 +0000 Subject: [PATCH 08/10] Stop stylizing PEP **518** This is a slightly cleaner presentation style. --- src/pip/_internal/exceptions.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/pip/_internal/exceptions.py b/src/pip/_internal/exceptions.py index 394ac6b1cca..48e79ea5612 100644 --- a/src/pip/_internal/exceptions.py +++ b/src/pip/_internal/exceptions.py @@ -188,7 +188,7 @@ def __init__(self, *, package: str) -> None: "The [build-system] table is missing the mandatory `requires` key." ), note_stmt="This is an issue with the package mentioned above, not pip.", - hint_stmt="See PEP 518 for the detailed specification.", + hint_stmt=Text("See PEP 518 for the detailed specification."), ) @@ -205,7 +205,7 @@ def __init__(self, *, package: str, reason: str) -> None: f"pyproject.toml.\n{reason}" ), note_stmt="This is an issue with the package mentioned above, not pip.", - hint_stmt="See PEP 518 for the detailed specification.", + hint_stmt=Text("See PEP 518 for the detailed specification."), ) From 6b31f83187edf1c566269bc276309091fe8a6509 Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Sun, 12 Dec 2021 13:13:02 +0000 Subject: [PATCH 09/10] Escape the package name, allowing rich to stylize URLs and links --- src/pip/_internal/exceptions.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/pip/_internal/exceptions.py b/src/pip/_internal/exceptions.py index 48e79ea5612..952e063d789 100644 --- a/src/pip/_internal/exceptions.py +++ b/src/pip/_internal/exceptions.py @@ -7,6 +7,7 @@ from pip._vendor.requests.models import Request, Response from pip._vendor.rich.console import Console, ConsoleOptions, RenderResult +from pip._vendor.rich.markup import escape from pip._vendor.rich.text import Text if TYPE_CHECKING: @@ -182,7 +183,7 @@ class MissingPyProjectBuildRequires(DiagnosticPipError): def __init__(self, *, package: str) -> None: super().__init__( - message=Text(f"Can not process {package}"), + message=f"Can not process {escape(package)}", context=Text( "This package has an invalid pyproject.toml file.\n" "The [build-system] table is missing the mandatory `requires` key." @@ -199,7 +200,7 @@ class InvalidPyProjectBuildRequires(DiagnosticPipError): def __init__(self, *, package: str, reason: str) -> None: super().__init__( - message=Text(f"Can not process {package}"), + message=f"Can not process {escape(package)}", context=Text( "This package has an invalid `build-system.requires` key in " f"pyproject.toml.\n{reason}" From fd4582506317be93588411106f633627f4a7d518 Mon Sep 17 00:00:00 2001 From: Pradyun Gedam Date: Sun, 12 Dec 2021 13:30:06 +0000 Subject: [PATCH 10/10] Apply suggestions from code review Co-authored-by: Hugo van Kemenade --- news/10703.feature.rst | 2 +- src/pip/_internal/utils/logging.py | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/news/10703.feature.rst b/news/10703.feature.rst index 39812e6bed6..4094f41405c 100644 --- a/news/10703.feature.rst +++ b/news/10703.feature.rst @@ -1 +1 @@ -Start utilising ``rich`` for presenting error messages in a consistent format. +Start using Rich for presenting error messages in a consistent format. diff --git a/src/pip/_internal/utils/logging.py b/src/pip/_internal/utils/logging.py index 0d505dc87bf..1c0cd8e261e 100644 --- a/src/pip/_internal/utils/logging.py +++ b/src/pip/_internal/utils/logging.py @@ -147,7 +147,7 @@ def __init__(self, stream: Optional[TextIO], no_color: bool) -> None: highlighter=NullHighlighter(), ) - # Our custom override on rich's logger, to make things work as we need them to. + # Our custom override on Rich's logger, to make things work as we need them to. def emit(self, record: logging.LogRecord) -> None: style: Optional[Style] = None