From ac61d71c4c48657c9ea2da9c5c0a2a78d2675e7a Mon Sep 17 00:00:00 2001 From: Jeremy Fleischman Date: Wed, 5 Jun 2024 20:45:18 -0700 Subject: [PATCH] Don't assume that `LogRecord.args` is a tuple In the context of pip, and especially when `rich=True`, I bet it *is* true that `LogRecord.args` is always a tuple. However, in general, this is not true. Single argument dicts actually [are treated specially by Python's logging infrastructure](https://github.com/python/cpython/blob/v3.11.9/Lib/logging/__init__.py#L301-L320): >>> def build_record(*args): ... return LogRecord(name="name", level=0, pathname="pathname", lineno=42, msg="msg", args=args, exc_info=False).args ... >>> build_record({"foo": 42}, {"bar": 43}) ({'foo': 42}, {'bar': 43}) # <-- this is a tuple! >>> build_record(42) (42,) # <-- this is a tuple! >>> build_record({"foo": 42}) {'foo': 42} # <-- this is not a tuple! This fixes https://github.com/pypa/pip/issues/12751 While I was in here, I also changed our logging story so we can actually capture the full stacktrace when logging is turned up. That would have been quite useful for me when debugging this issue, and would also be useful for folks debugging keyring backends. Hopefully this is uncontroversial. Happy to split this out into a separate PR if folks prefer. --- news/12751.bugfix.rst | 1 + src/pip/_internal/network/auth.py | 4 ++++ src/pip/_internal/utils/logging.py | 2 +- 3 files changed, 6 insertions(+), 1 deletion(-) create mode 100644 news/12751.bugfix.rst diff --git a/news/12751.bugfix.rst b/news/12751.bugfix.rst new file mode 100644 index 00000000000..70c6680a8a9 --- /dev/null +++ b/news/12751.bugfix.rst @@ -0,0 +1 @@ +Avoid keyring logging crashes when pip is run in verbose mode. diff --git a/src/pip/_internal/network/auth.py b/src/pip/_internal/network/auth.py index 4705b55a7aa..1a2606ed080 100644 --- a/src/pip/_internal/network/auth.py +++ b/src/pip/_internal/network/auth.py @@ -271,6 +271,10 @@ def _get_keyring_auth( try: return self.keyring_provider.get_auth_info(url, username) except Exception as exc: + # Log the full exception (with stacktrace) at debug, so it'll only + # show up when running in verbose mode. + logger.debug("Keyring is skipped due to an exception", exc_info=True) + # Always log a shortened version of the exception. logger.warning( "Keyring is skipped due to an exception: %s", str(exc), diff --git a/src/pip/_internal/utils/logging.py b/src/pip/_internal/utils/logging.py index 90df257821e..41f6eb51a26 100644 --- a/src/pip/_internal/utils/logging.py +++ b/src/pip/_internal/utils/logging.py @@ -154,8 +154,8 @@ def emit(self, record: logging.LogRecord) -> None: style: Optional[Style] = None # If we are given a diagnostic error to present, present it with indentation. - assert isinstance(record.args, tuple) if getattr(record, "rich", False): + assert isinstance(record.args, tuple) (rich_renderable,) = record.args assert isinstance( rich_renderable, (ConsoleRenderable, RichCast, str)