22.1: pip upgrade warning is causing numerous test failures when offline

[mgorny]

Description

When running the pip's test suite without Internet access, the newly added:

logger.warning("There was an error checking the latest version of pip.")

i causing numerous tests to fail with an error similar to the following:

E               RuntimeError: stderr has an unexpected warning (pass allow_stderr_warning=True to permit this):
E                Caused by line: 'WARNING: There was an error checking the latest version of pip.'
E                Complete stderr: WARNING: There was an error checking the latest version of pip.

An example failing test is tests/functional/test_list.py::test_local_flag.

Expected behavior

The majority of tests passing.

pip version

22.1

Python version

3.8.13, 3.9.12, 3.10.4

OS

Gentoo Linux

How to Reproduce

1. Do the usual prep (install pip & deps, copy common wheels, set envvars).
2. Disable the Internet access (e.g. using unshare -n).
3. rm -r ~/.pip/cache
4. python -m pytest -m "not network" tests/functional/test_list.py::test_local_flag

Output

============================= test session starts ==============================
platform linux -- Python 3.9.12, pytest-7.1.2, pluggy-1.0.0
rootdir: /tmp/pip-22.1, configfile: setup.cfg
plugins: xdist-2.5.0, cov-3.0.0, forked-1.4.0, rerunfailures-10.2
collected 1 item

tests/functional/test_list.py F                                          [100%]

=================================== FAILURES ===================================
_______________________________ test_local_flag ________________________________

simple_script = <tests.lib.PipTestEnvironment object at 0x7fe1ee6c6e50>

    def test_local_flag(simple_script: PipTestEnvironment) -> None:
        """
        Test the behavior of --local flag in the list command
    
        """
>       result = simple_script.pip("list", "--local", "--format=json")

tests/functional/test_list.py:99: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
tests/lib/__init__.py:671: in run
    _check_stderr(
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

stderr = 'WARNING: There was an error checking the latest version of pip.\n'
allow_stderr_warning = False, allow_stderr_error = False

    def _check_stderr(
        stderr: str,
        allow_stderr_warning: bool,
        allow_stderr_error: bool,
    ) -> None:
        """
        Check the given stderr for logged warnings and errors.
    
        :param stderr: stderr output as a string.
        :param allow_stderr_warning: whether a logged warning (or deprecation
            message) is allowed. Must be True if allow_stderr_error is True.
        :param allow_stderr_error: whether a logged error is allowed.
        """
        assert not (allow_stderr_error and not allow_stderr_warning)
    
        lines = stderr.splitlines()
        for line in lines:
            # First check for logging errors, which we don't allow during
            # tests even if allow_stderr_error=True (since a logging error
            # would signal a bug in pip's code).
            #    Unlike errors logged with logger.error(), these errors are
            # sent directly to stderr and so bypass any configured log formatter.
            # The "--- Logging error ---" string is used in Python 3.4+, and
            # "Logged from file " is used in Python 2.
            if line.startswith("--- Logging error ---") or line.startswith(
                "Logged from file "
            ):
                reason = "stderr has a logging error, which is never allowed"
                msg = make_check_stderr_message(stderr, line=line, reason=reason)
                raise RuntimeError(msg)
            if allow_stderr_error:
                continue
    
            if line.startswith("ERROR: "):
                reason = (
                    "stderr has an unexpected error "
                    "(pass allow_stderr_error=True to permit this)"
                )
                msg = make_check_stderr_message(stderr, line=line, reason=reason)
                raise RuntimeError(msg)
            if allow_stderr_warning:
                continue
    
            if line.startswith("WARNING: ") or line.startswith(DEPRECATION_MSG_PREFIX):
                reason = (
                    "stderr has an unexpected warning "
                    "(pass allow_stderr_warning=True to permit this)"
                )
                msg = make_check_stderr_message(stderr, line=line, reason=reason)
>               raise RuntimeError(msg)
E               RuntimeError: stderr has an unexpected warning (pass allow_stderr_warning=True to permit this):
E                Caused by line: 'WARNING: There was an error checking the latest version of pip.'
E                Complete stderr: WARNING: There was an error checking the latest version of pip.

tests/lib/__init__.py:468: RuntimeError
---------------------------- Captured stdout setup -----------------------------
Using base prefix '/usr'
New python executable in /tmp/pytest-of-mgorny/pytest-0/virtualenv0/venv_orig/bin/python
---------------------------- Captured stderr setup -----------------------------
/tmp/pytest-of-mgorny/pytest-0/setuptools0/install/setuptools/command/easy_install.py:144: EasyInstallDeprecationWarning: easy_install command is deprecated. Use build and pip and other standards-based tools.
  warnings.warn(
/tmp/pytest-of-mgorny/pytest-0/setuptools0/install/setuptools/command/install.py:34: SetuptoolsDeprecationWarning: setup.py install is 
deprecated. Use build and pip and other standards-based tools.
  warnings.warn(
warning: no files found matching 'docs/docutils.conf'
warning: no files found matching 'docs/requirements.txt'
warning: no previously-included files found matching '.coveragerc'
warning: no previously-included files found matching '.mailmap'
warning: no previously-included files found matching '.appveyor.yml'
warning: no previously-included files found matching '.readthedocs.yml'
warning: no previously-included files found matching '.pre-commit-config.yaml'
warning: no previously-included files found matching 'tox.ini'
warning: no previously-included files found matching 'noxfile.py'
warning: no files found matching '*.css' under directory 'docs'
warning: no files found matching '*.py' under directory 'docs'
warning: no files found matching '*.rst' under directory 'docs'
warning: no files found matching '*.md' under directory 'docs'
warning: no previously-included files found matching 'src/pip/_vendor/six'
warning: no previously-included files found matching 'src/pip/_vendor/six/moves'
warning: no previously-included files matching '*.pyi' found under directory 'src/pip/_vendor'
no previously-included directories found matching '.github'
no previously-included directories found matching 'docs/build'
no previously-included directories found matching 'news'
no previously-included directories found matching 'tasks'
no previously-included directories found matching 'tests'
no previously-included directories found matching 'tools'
=========================== short test summary info ============================
FAILED tests/functional/test_list.py::test_local_flag - RuntimeError: stderr ...
============================== 1 failed in 12.67s ==============================

Code of Conduct

• I agree to follow the PSF Code of Conduct.

[ichard26]

@mgorny is this still a problem for you? I can take a look if so.

[mgorny]

I've just set PIP_DISABLE_PIP_VERSION_CHECK=1, so not really — though I suppose it still happens if you don't do that.