[blinkpy] Make it possible to debug failing fuzzy ref-tests

With this change, passing --debug-rwt-logging to run_web_tests.py will
cause base.py to print the difference for a failing reftest to the
console. A better solution would be to parse the data from image_diff
and pass it back up the stack to be embedded in the results, but this
approach is quick and works.

Bug: 997202
Change-Id: I541110cdafa18287fc47856c71a2c41427cf297d
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2575455Reviewed-by: Dirk Pranke <dpranke@google.com>
Reviewed-by: Robert Ma <robertma@chromium.org>
Commit-Queue: Stephen McGruer <smcgruer@chromium.org>
Cr-Commit-Position: refs/heads/master@{#834473}

third_party/blink/tools/blinkpy/common/system/executive.py

@@ -329,7 +329,34 @@ class Executive(object):
             ignore_stderr=False,
             decode_output=True,
             debug_logging=True):
-        """Popen wrapper for convenience and to work around python bugs."""
+        """Popen wrapper for convenience and to work around python bugs.
+
+        By default, run_command will expect a zero exit code and will return the
+        program output in that case, or throw a ScriptError if the program has a
+        non-zero exit code. This behavior can be changed by setting the
+        appropriate input parameters.
+
+        Args:
+            args: the program arguments. Passed to Popen.
+            cwd: the current working directory for the program. Passed to Popen.
+            env: the environment for the program. Passed to Popen.
+            input: input to give to the program on stdin. Accepts either a file
+                handler (will be passed directly) or a string (will be passed
+                via a pipe).
+            timeout_seconds: maximum time in seconds to wait for the program to
+                terminate; on a timeout the process will be killed
+            error_handler: a custom error handler called with a ScriptError when
+                the program fails. The default handler raises the error.
+            return_exit_code: instead of returning the program output, return
+                the exit code. Setting this makes non-zero exit codes non-fatal
+                (the error_handler will not be called).
+            return_stderr: if True, include stderr in the returned output. If
+                False, stderr will be printed to the console unless ignore_stderr
+                is also True.
+            ignore_stderr: squash stderr so it doesn't appear in the console.
+            decode_output: whether to decode the program output.
+            debug_logging: whether to log details about program execution.
+        """
         assert isinstance(args, list) or isinstance(args, tuple)
         start_time = time.time()
 

third_party/blink/tools/blinkpy/common/system/executive_mock.py

@@ -148,7 +148,9 @@ class MockExecutive(object):
         if self._exception:
             raise self._exception  # pylint: disable=raising-bad-type
         if self._should_throw:
-            raise ScriptError('MOCK ScriptError', output=self._output)
+            raise ScriptError('MOCK ScriptError',
+                              output=self._output,
+                              exit_code=self._exit_code)
 
         if self._run_command_fn:
             return self._run_command_fn(args)

third_party/blink/tools/blinkpy/web_tests/port/base.py

@@ -46,6 +46,7 @@ from blinkpy.common import find_files
 from blinkpy.common import read_checksum_from_png
 from blinkpy.common import path_finder
 from blinkpy.common.memoized import memoized
+from blinkpy.common.system.executive import ScriptError
 from blinkpy.common.system.path import abspath_to_uri
 from blinkpy.w3c.wpt_manifest import WPTManifest, MANIFEST_NAME
 from blinkpy.web_tests.layout_package.bot_test_expectations import BotTestExpectationsFactory
@@ -584,15 +585,19 @@ class Port(object):
         result = None
         err_str = None
         try:
-            exit_code = self._executive.run_command(
-                command, return_exit_code=True)
-            if exit_code == 0:
-                # The images are the same.
-                result = None
-            elif exit_code == 1:
+            output = self._executive.run_command(command)
+            # Log the output, to enable user debugging of a diff hidden by fuzzy
+            # expectations. This is useful when tightening fuzzy bounds.
+            if output:
+                _log.debug(output)
+        except ScriptError as error:
+            if error.exit_code == 1:
                 result = self._filesystem.read_binary_file(diff_filename)
+                # Log the output, to enable user debugging of the diff.
+                if error.output:
+                    _log.debug(error.output)
             else:
-                err_str = 'Image diff returned an exit code of %s. See http://crbug.com/278596' % exit_code
+                err_str = 'Image diff returned an exit code of %s. See http://crbug.com/278596' % error.exit_code
         except OSError as error:
             err_str = 'error running image diff: %s' % error
         finally:

third_party/blink/tools/blinkpy/web_tests/port/port_testcase.py

@@ -31,6 +31,7 @@ import collections
 import optparse
 
 from blinkpy.common import exit_codes
+from blinkpy.common.system.executive import ScriptError
 from blinkpy.common.system.executive_mock import MockExecutive
 from blinkpy.common.system.log_testing import LoggingTestCase
 from blinkpy.common.system.system_host import SystemHost
@@ -201,7 +202,7 @@ class PortTestCase(LoggingTestCase):
 
         def mock_run_command(args):
             port.host.filesystem.write_binary_file(args[4], mock_image_diff)
-            return 1
+            raise ScriptError(exit_code=1)
 
         # Images are different.
         port._executive = MockExecutive(run_command_fn=mock_run_command)  # pylint: disable=protected-access
@@ -223,7 +224,7 @@ class PortTestCase(LoggingTestCase):
 
     def test_diff_image_crashed(self):
         port = self.make_port()
-        port._executive = MockExecutive(exit_code=2)  # pylint: disable=protected-access
+        port._executive = MockExecutive(should_throw=True, exit_code=2)  # pylint: disable=protected-access
         self.assertEqual(
             port.diff_image('EXPECTED', 'ACTUAL'),
             (None,

tools/imagediff/image_diff.cc

@@ -425,6 +425,11 @@ bool CreateImageDiff(const Image& image1,
     }
   }
 
+  if (!same) {
+    printf("Found pixels_different: %d, max_channel_diff: %u\n",
+           pixels_different, max_channel_diff);
+  }
+
   if (!fuzzy_diff) {
     return same;
   }
@@ -436,11 +441,9 @@ bool CreateImageDiff(const Image& image1,
 
   // WPT fuzzy matching. This algorithm is equivalent to 'check_pass' in
   // tools/wptrunner/wptrunner/executors/base.py
-  fprintf(stderr, "Found pixels_different: %d, max_channel_diff: %u\n",
-          pixels_different, max_channel_diff);
-  fprintf(stderr, "Allowed pixels different; %d-%d, channel diff: %u-%u\n",
-          fuzzy_allowed_pixels_diff[0], fuzzy_allowed_pixels_diff[1],
-          fuzzy_allowed_max_channel_diff[0], fuzzy_allowed_max_channel_diff[1]);
+  printf("Allowed pixels_different; %d-%d, max_channel_diff: %u-%u\n",
+         fuzzy_allowed_pixels_diff[0], fuzzy_allowed_pixels_diff[1],
+         fuzzy_allowed_max_channel_diff[0], fuzzy_allowed_max_channel_diff[1]);
 
   return ((pixels_different == 0 && fuzzy_allowed_pixels_diff[0] == 0) ||
           (max_channel_diff == 0 && fuzzy_allowed_max_channel_diff[0] == 0) ||