keyring import provider fails if pip is run with -vv or -vvv

[jfly]

Description

If a custom keyring backend has a log line like this:

logger.debug("This is a debug message: %s", {"foo": 42})

Then pip ends up blowing up on this assertion here: https://github.com/pypa/pip/blob/24.0/src/pip/_internal/utils/logging.py#L157, which gets handled here: https://github.com/pypa/pip/blob/24.0/src/pip/_internal/network/auth.py#L273-L276 and turns into a "WARNING: Keyring is skipped due to an exception:".

This is because of this kind of surprising behavior in logging.LogRecord's constructor which unwraps a tuple containing exactly 1 dict into that dict. This renders pip's logging assertion incorrect. It's possible that pip (and all of it dependencies) never actually emit logs like this, but keyring's support for pluggable backends means arbitrary Python packages can end up running in the same Python instance as pip.

It looks like pip gained this assertion recently, as part of some work with black: 2cfe36d#diff-95ff72558ab480897cdc6eb482d532d9d9809247df6992ca11b62611cf39496bR156

Expected behavior

Valid log lines as described above should not cause a keyring to crash.

pip version

24.0

Python version

3.11.9

OS

NixOS

How to Reproduce

I put together a simple repro on https://github.com/jfly/2024-06-05-pip-keyring-logging-bug. To check it out:

git clone https://github.com/jfly/2024-06-05-pip-keyring-logging-bug
cd 2024-06-05-pip-keyring-logging-bug
python -m venv .venv
source .venv/bin/activate
pip install -r requirements.txt

pip -vv --keyring-provider import install --index-url https://httpstat.us/401 requests

This will fail with a "WARNING: Keyring is skipped due to an exception:", but will succeed if you remove the -vv parameter to pip.

Output

$ git clone https://github.com/jfly/2024-06-05-pip-keyring-logging-bug
$ cd 2024-06-05-pip-keyring-logging-bug
$ python -m venv .venv
$ source .venv/bin/activate
$ pip install -r requirements.txt
...

$ pip -vv --keyring-provider import install --index-url https://httpstat.us/401 requests
Using pip 24.0 from /home/jeremy/tmp/2024-06-05-pyhack-2/.direnv/python-3.11.9/lib/python3.11/site-packages/pip (python 3.11)
Non-user install because user site-packages disabled
Created temporary directory: /run/user/1000/pip-build-tracker-nn_sm5wc
Initialized build tracking at /run/user/1000/pip-build-tracker-nn_sm5wc
Created build tracker: /run/user/1000/pip-build-tracker-nn_sm5wc
Entered build tracker: /run/user/1000/pip-build-tracker-nn_sm5wc
Created temporary directory: /run/user/1000/pip-install-ym1lagii
Created temporary directory: /run/user/1000/pip-ephem-wheel-cache-h6x7xfz9
Looking in indexes: https://httpstat.us/401
1 location(s) to search for versions of requests:
* https://httpstat.us/401/requests/
Fetching project page and analyzing links: https://httpstat.us/401/requests/
Getting page https://httpstat.us/401/requests/
Found index url https://httpstat.us/401/
Looking up "https://httpstat.us/401/requests/" in the cache
Request header has "max_age" as 0, cache bypassed
No cache entry available
Starting new HTTPS connection (1): httpstat.us:443
https://httpstat.us:443 "GET /401/requests/ HTTP/1.1" 401 16
Found index url https://httpstat.us/401/
Keyring provider requested: import
Keyring provider set: import
Getting credentials from keyring for https://httpstat.us/401/
Loading jfly backend
Loading KWallet
Loading SecretService
Loading Windows
Loading chainer
Loading libsecret
Loading macOS
Hello from JflyBackend::get_credential. I'm about to log a message
WARNING: Keyring is skipped due to an exception:
Keyring provider requested: import
Keyring provider set: disabled
User for httpstat.us:

Code of Conduct

• I agree to follow the PSF Code of Conduct.