Don't allow logging errors during tests even if allow_stderr_error=True

tests/lib/__init__.py

@@ -294,26 +294,28 @@ def check_stderr(
     if allow_stderr_warning is None:
         allow_stderr_warning = allow_stderr_error
 
-    if allow_stderr_error:
-        # Then any stderr is acceptable.
-        if not allow_stderr_warning:
-            raise RuntimeError(
-                'cannot pass allow_stderr_warning=False with '
-                'allow_stderr_error=True'
-            )
-        return
+    if allow_stderr_error and not allow_stderr_warning:
+        raise RuntimeError(
+            'cannot pass allow_stderr_warning=False with '
+            'allow_stderr_error=True'
+        )
 
     lines = stderr.splitlines()
     for line in lines:
-        # First check for logging errors which are sent directly to stderr
-        # and so bypass any configured log formatter.  The
-        # "--- Logging error ---" string is used in Python 3.4+, and
+        # 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 = (

tests/lib/test_lib.py

@@ -80,7 +80,16 @@ def test_as_import(script):
 
 class TestPipTestEnvironment:
 
-    def run_with_log_command(self, script, sub_string):
+    def run_stderr_with_prefix(self, script, prefix, **kwargs):
+        """
+        Call run() that prints stderr with the given prefix.
+        """
+        text = '{}: hello, world\\n'.format(prefix)
+        command = 'import sys; sys.stderr.write("{}")'.format(text)
+        args = [sys.executable, '-c', command]
+        script.run(*args, **kwargs)
+
+    def run_with_log_command(self, script, sub_string, **kwargs):
         """
         Call run() on a command that logs a "%"-style format string using
         the given substring as the string's replacement field.
@@ -90,15 +99,6 @@ def run_with_log_command(self, script, sub_string):
             "logging.getLogger().info('sub: {}', 'foo')"
         ).format(sub_string)
         args = [sys.executable, '-c', command]
-        script.run(*args)
-
-    def run_stderr_with_prefix(self, script, prefix, **kwargs):
-        """
-        Call run() that prints stderr with the given prefix.
-        """
-        text = '{}: hello, world\\n'.format(prefix)
-        command = 'import sys; sys.stderr.write("{}")'.format(text)
-        args = [sys.executable, '-c', command]
         script.run(*args, **kwargs)
 
     @pytest.mark.parametrize('prefix', (
@@ -162,8 +162,13 @@ def test_run__logging_error(self, script):
 
         expected_start = 'stderr has a logging error, which is never allowed'
         with assert_error_startswith(RuntimeError, expected_start):
-            # Pass a bad substitution string.
-            self.run_with_log_command(script, sub_string='{!r}')
+            # Pass a bad substitution string.  Also, pass
+            # allow_stderr_error=True to check that the RuntimeError occurs
+            # even under the stricter test condition of when we are allowing
+            # other types of errors.
+            self.run_with_log_command(
+                script, sub_string='{!r}', allow_stderr_error=True,
+            )
 
     def test_run__allow_stderr_error_false_error_with_expect_error(
         self, script,