WebKitTools/Scripts/webkitpy/layout_tests/layout_package/dump_render_tree_thread.py

   1 #!/usr/bin/env python
   2 # Copyright (C) 2010 Google Inc. All rights reserved.
   3 # Copyright (C) 2010 Gabor Rapcsanyi (rgabor@inf.u-szeged.hu), University of Szeged
   4 #
   5 # Redistribution and use in source and binary forms, with or without
   6 # modification, are permitted provided that the following conditions are
   7 # met:
   8 #
   9 #     * Redistributions of source code must retain the above copyright
  10 # notice, this list of conditions and the following disclaimer.
  11 #     * Redistributions in binary form must reproduce the above
  12 # copyright notice, this list of conditions and the following disclaimer
  13 # in the documentation and/or other materials provided with the
  14 # distribution.
  15 #     * Neither the name of Google Inc. nor the names of its
  16 # contributors may be used to endorse or promote products derived from
  17 # this software without specific prior written permission.
  18 #
  19 # THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
  20 # "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
  21 # LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
  22 # A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
  23 # OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
  24 # SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
  25 # LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
  26 # DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
  27 # THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
  28 # (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
  29 # OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
  30
  31 """A Thread object for running DumpRenderTree and processing URLs from a
  32 shared queue.
  33
  34 Each thread runs a separate instance of the DumpRenderTree binary and validates
  35 the output.  When there are no more URLs to process in the shared queue, the
  36 thread exits.
  37 """
  38
  39 from __future__ import with_statement
  40
  41 import codecs
  42 import copy
  43 import logging
  44 import os
  45 import Queue
  46 import signal
  47 import sys
  48 import thread
  49 import threading
  50 import time
  51
  52 import test_failures
  53 import test_output
  54 import test_results
  55
  56 _log = logging.getLogger("webkitpy.layout_tests.layout_package."
  57                          "dump_render_tree_thread")
  58
  59
  60 def _expected_test_output(port, filename):
  61     """Returns an expected TestOutput object."""
  62     return test_output.TestOutput(port.expected_text(filename),
  63                                   port.expected_image(filename),
  64                                   port.expected_checksum(filename))
  65
  66 def _process_output(port, options, test_input, test_types, test_args,
  67                     test_output):
  68     """Receives the output from a DumpRenderTree process, subjects it to a
  69     number of tests, and returns a list of failure types the test produced.
  70
  71     Args:
  72       port: port-specific hooks
  73       options: command line options argument from optparse
  74       proc: an active DumpRenderTree process
  75       test_input: Object containing the test filename and timeout
  76       test_types: list of test types to subject the output to
  77       test_args: arguments to be passed to each test
  78       test_output: a TestOutput object containing the output of the test
  79
  80     Returns: a TestResult object
  81     """
  82     failures = []
  83
  84     if test_output.crash:
  85         failures.append(test_failures.FailureCrash())
  86     if test_output.timeout:
  87         failures.append(test_failures.FailureTimeout())
  88
  89     if test_output.crash:
  90         _log.debug("Stacktrace for %s:\n%s" % (test_input.filename,
  91                                                test_output.error))
  92         # Strip off "file://" since RelativeTestFilename expects
  93         # filesystem paths.
  94         filename = os.path.join(options.results_directory,
  95                                 port.relative_test_filename(
  96                                 test_input.filename))
  97         filename = os.path.splitext(filename)[0] + "-stack.txt"
  98         port.maybe_make_directory(os.path.split(filename)[0])
  99         with codecs.open(filename, "wb", "utf-8") as file:
 100             file.write(test_output.error)
 101     elif test_output.error:
 102         _log.debug("Previous test output stderr lines:\n%s" % test_output.error)
 103
 104     expected_test_output = _expected_test_output(port, test_input.filename)
 105
 106     # Check the output and save the results.
 107     start_time = time.time()
 108     time_for_diffs = {}
 109     for test_type in test_types:
 110         start_diff_time = time.time()
 111         new_failures = test_type.compare_output(port, test_input.filename,
 112                                                 test_args, test_output,
 113                                                 expected_test_output)
 114         # Don't add any more failures if we already have a crash, so we don't
 115         # double-report those tests. We do double-report for timeouts since
 116         # we still want to see the text and image output.
 117         if not test_output.crash:
 118             failures.extend(new_failures)
 119         time_for_diffs[test_type.__class__.__name__] = (
 120             time.time() - start_diff_time)
 121
 122     total_time_for_all_diffs = time.time() - start_diff_time
 123     return test_results.TestResult(test_input.filename, failures, test_output.test_time,
 124                                    total_time_for_all_diffs, time_for_diffs)
 125
 126
 127 def _pad_timeout(timeout):
 128     """Returns a safe multiple of the per-test timeout value to use
 129     to detect hung test threads.
 130
 131     """
 132     # When we're running one test per DumpRenderTree process, we can
 133     # enforce a hard timeout.  The DumpRenderTree watchdog uses 2.5x
 134     # the timeout; we want to be larger than that.
 135     return timeout * 3
 136
 137
 138 def _milliseconds_to_seconds(msecs):
 139     return float(msecs) / 1000.0
 140
 141
 142 def _should_fetch_expected_checksum(options):
 143     return options.pixel_tests and not (options.new_baseline or options.reset_results)
 144
 145
 146 def _run_single_test(port, options, test_input, test_types, test_args, driver):
 147     # FIXME: Pull this into TestShellThread._run().
 148
 149     # The image hash is used to avoid doing an image dump if the
 150     # checksums match, so it should be set to a blank value if we
 151     # are generating a new baseline.  (Otherwise, an image from a
 152     # previous run will be copied into the baseline."""
 153     if _should_fetch_expected_checksum(options):
 154         image_hash_to_driver = port.expected_checksum(test_input.filename)
 155     else:
 156         image_hash_to_driver = None
 157     uri = port.filename_to_uri(test_input.filename)
 158     test_output = driver.run_test(uri, test_input.timeout, image_hash_to_driver)
 159     return _process_output(port, options, test_input, test_types, test_args,
 160                            test_output)
 161
 162
 163 class SingleTestThread(threading.Thread):
 164     """Thread wrapper for running a single test file."""
 165
 166     def __init__(self, port, options, test_input, test_types, test_args):
 167         """
 168         Args:
 169           port: object implementing port-specific hooks
 170           options: command line argument object from optparse
 171           test_input: Object containing the test filename and timeout
 172           test_types: A list of TestType objects to run the test output
 173               against.
 174           test_args: A TestArguments object to pass to each TestType.
 175         """
 176
 177         threading.Thread.__init__(self)
 178         self._port = port
 179         self._options = options
 180         self._test_input = test_input
 181         self._test_types = test_types
 182         self._test_args = test_args
 183         self._driver = None
 184
 185     def run(self):
 186         self._covered_run()
 187
 188     def _covered_run(self):
 189         # FIXME: this is a separate routine to work around a bug
 190         # in coverage: see http://bitbucket.org/ned/coveragepy/issue/85.
 191         self._driver = self._port.create_driver(self._test_args.png_path,
 192                                                 self._options)
 193         self._driver.start()
 194         self._test_result = _run_single_test(self._port, self._options,
 195                                              self._test_input, self._test_types,
 196                                              self._test_args, self._driver)
 197         self._driver.stop()
 198
 199     def get_test_result(self):
 200         return self._test_result
 201
 202
 203 class WatchableThread(threading.Thread):
 204     """This class abstracts an interface used by
 205     run_webkit_tests.TestRunner._wait_for_threads_to_finish for thread
 206     management."""
 207     def __init__(self):
 208         threading.Thread.__init__(self)
 209         self._canceled = False
 210         self._exception_info = None
 211         self._next_timeout = None
 212         self._thread_id = None
 213
 214     def cancel(self):
 215         """Set a flag telling this thread to quit."""
 216         self._canceled = True
 217
 218     def clear_next_timeout(self):
 219         """Mark a flag telling this thread to stop setting timeouts."""
 220         self._timeout = 0
 221
 222     def exception_info(self):
 223         """If run() terminated on an uncaught exception, return it here
 224         ((type, value, traceback) tuple).
 225         Returns None if run() terminated normally. Meant to be called after
 226         joining this thread."""
 227         return self._exception_info
 228
 229     def id(self):
 230         """Return a thread identifier."""
 231         return self._thread_id
 232
 233     def next_timeout(self):
 234         """Return the time the test is supposed to finish by."""
 235         return self._next_timeout
 236
 237
 238 class TestShellThread(WatchableThread):
 239     def __init__(self, port, options, filename_list_queue, result_queue,
 240                  test_types, test_args):
 241         """Initialize all the local state for this DumpRenderTree thread.
 242
 243         Args:
 244           port: interface to port-specific hooks
 245           options: command line options argument from optparse
 246           filename_list_queue: A thread safe Queue class that contains lists
 247               of tuples of (filename, uri) pairs.
 248           result_queue: A thread safe Queue class that will contain
 249               serialized TestResult objects.
 250           test_types: A list of TestType objects to run the test output
 251               against.
 252           test_args: A TestArguments object to pass to each TestType.
 253         """
 254         WatchableThread.__init__(self)
 255         self._port = port
 256         self._options = options
 257         self._filename_list_queue = filename_list_queue
 258         self._result_queue = result_queue
 259         self._filename_list = []
 260         self._test_types = test_types
 261         self._test_args = test_args
 262         self._driver = None
 263         self._test_group_timing_stats = {}
 264         self._test_results = []
 265         self._num_tests = 0
 266         self._start_time = 0
 267         self._stop_time = 0
 268         self._have_http_lock = False
 269         self._http_lock_wait_begin = 0
 270         self._http_lock_wait_end = 0
 271
 272         # Current group of tests we're running.
 273         self._current_group = None
 274         # Number of tests in self._current_group.
 275         self._num_tests_in_current_group = None
 276         # Time at which we started running tests from self._current_group.
 277         self._current_group_start_time = None
 278
 279     def get_test_group_timing_stats(self):
 280         """Returns a dictionary mapping test group to a tuple of
 281         (number of tests in that group, time to run the tests)"""
 282         return self._test_group_timing_stats
 283
 284     def get_test_results(self):
 285         """Return the list of all tests run on this thread.
 286
 287         This is used to calculate per-thread statistics.
 288
 289         """
 290         return self._test_results
 291
 292     def get_total_time(self):
 293         return max(self._stop_time - self._start_time -
 294                    self._http_lock_wait_time(), 0.0)
 295
 296     def get_num_tests(self):
 297         return self._num_tests
 298
 299     def run(self):
 300         """Delegate main work to a helper method and watch for uncaught
 301         exceptions."""
 302         self._covered_run()
 303
 304     def _covered_run(self):
 305         # FIXME: this is a separate routine to work around a bug
 306         # in coverage: see http://bitbucket.org/ned/coveragepy/issue/85.
 307         self._thread_id = thread.get_ident()
 308         self._start_time = time.time()
 309         self._num_tests = 0
 310         try:
 311             _log.debug('%s starting' % (self.getName()))
 312             self._run(test_runner=None, result_summary=None)
 313             _log.debug('%s done (%d tests)' % (self.getName(),
 314                        self.get_num_tests()))
 315         except KeyboardInterrupt:
 316             self._exception_info = sys.exc_info()
 317             _log.debug("%s interrupted" % self.getName())
 318         except:
 319             # Save the exception for our caller to see.
 320             self._exception_info = sys.exc_info()
 321             self._stop_time = time.time()
 322             _log.error('%s dying, exception raised' % self.getName())
 323
 324         self._stop_time = time.time()
 325
 326     def run_in_main_thread(self, test_runner, result_summary):
 327         """This hook allows us to run the tests from the main thread if
 328         --num-test-shells==1, instead of having to always run two or more
 329         threads. This allows us to debug the test harness without having to
 330         do multi-threaded debugging."""
 331         self._run(test_runner, result_summary)
 332
 333     def cancel(self):
 334         """Clean up http lock and set a flag telling this thread to quit."""
 335         self._stop_servers_with_lock()
 336         WatchableThread.cancel(self)
 337
 338     def next_timeout(self):
 339         """Return the time the test is supposed to finish by."""
 340         if self._next_timeout:
 341             return self._next_timeout + self._http_lock_wait_time()
 342         return self._next_timeout
 343
 344     def _http_lock_wait_time(self):
 345         """Return the time what http locking takes."""
 346         if self._http_lock_wait_begin == 0:
 347             return 0
 348         if self._http_lock_wait_end == 0:
 349             return time.time() - self._http_lock_wait_begin
 350         return self._http_lock_wait_end - self._http_lock_wait_begin
 351
 352     def _run(self, test_runner, result_summary):
 353         """Main work entry point of the thread. Basically we pull urls from the
 354         filename queue and run the tests until we run out of urls.
 355
 356         If test_runner is not None, then we call test_runner.UpdateSummary()
 357         with the results of each test."""
 358         batch_size = self._options.batch_size
 359         batch_count = 0
 360
 361         # Append tests we're running to the existing tests_run.txt file.
 362         # This is created in run_webkit_tests.py:_PrepareListsAndPrintOutput.
 363         tests_run_filename = os.path.join(self._options.results_directory,
 364                                           "tests_run.txt")
 365         tests_run_file = codecs.open(tests_run_filename, "a", "utf-8")
 366
 367         while True:
 368             if self._canceled:
 369                 _log.debug('Testing cancelled')
 370                 tests_run_file.close()
 371                 return
 372
 373             if len(self._filename_list) is 0:
 374                 if self._current_group is not None:
 375                     self._test_group_timing_stats[self._current_group] = \
 376                         (self._num_tests_in_current_group,
 377                          time.time() - self._current_group_start_time)
 378
 379                 try:
 380                     self._current_group, self._filename_list = \
 381                         self._filename_list_queue.get_nowait()
 382                 except Queue.Empty:
 383                     self._stop_servers_with_lock()
 384                     self._kill_dump_render_tree()
 385                     tests_run_file.close()
 386                     return
 387
 388                 if self._current_group == "tests_to_http_lock":
 389                     self._start_servers_with_lock()
 390                 elif self._have_http_lock:
 391                     self._stop_servers_with_lock()
 392
 393                 self._num_tests_in_current_group = len(self._filename_list)
 394                 self._current_group_start_time = time.time()
 395
 396             test_input = self._filename_list.pop()
 397
 398             # We have a url, run tests.
 399             batch_count += 1
 400             self._num_tests += 1
 401             if self._options.run_singly:
 402                 result = self._run_test_singly(test_input)
 403             else:
 404                 result = self._run_test(test_input)
 405
 406             filename = test_input.filename
 407             tests_run_file.write(filename + "\n")
 408             if result.failures:
 409                 # Check and kill DumpRenderTree if we need to.
 410                 if len([1 for f in result.failures
 411                         if f.should_kill_dump_render_tree()]):
 412                     self._kill_dump_render_tree()
 413                     # Reset the batch count since the shell just bounced.
 414                     batch_count = 0
 415                 # Print the error message(s).
 416                 error_str = '\n'.join(['  ' + f.message() for
 417                                        f in result.failures])
 418                 _log.debug("%s %s failed:\n%s" % (self.getName(),
 419                            self._port.relative_test_filename(filename),
 420                            error_str))
 421             else:
 422                 _log.debug("%s %s passed" % (self.getName(),
 423                            self._port.relative_test_filename(filename)))
 424             self._result_queue.put(result.dumps())
 425
 426             if batch_size > 0 and batch_count >= batch_size:
 427                 # Bounce the shell and reset count.
 428                 self._kill_dump_render_tree()
 429                 batch_count = 0
 430
 431             if test_runner:
 432                 test_runner.update_summary(result_summary)
 433
 434     def _run_test_singly(self, test_input):
 435         """Run a test in a separate thread, enforcing a hard time limit.
 436
 437         Since we can only detect the termination of a thread, not any internal
 438         state or progress, we can only run per-test timeouts when running test
 439         files singly.
 440
 441         Args:
 442           test_input: Object containing the test filename and timeout
 443
 444         Returns:
 445           A TestResult
 446
 447         """
 448         worker = SingleTestThread(self._port,
 449                                   self._options,
 450                                   test_input,
 451                                   self._test_types,
 452                                   self._test_args)
 453
 454         worker.start()
 455
 456         thread_timeout = _milliseconds_to_seconds(
 457             _pad_timeout(int(test_input.timeout)))
 458         thread._next_timeout = time.time() + thread_timeout
 459         worker.join(thread_timeout)
 460         if worker.isAlive():
 461             # If join() returned with the thread still running, the
 462             # DumpRenderTree is completely hung and there's nothing
 463             # more we can do with it.  We have to kill all the
 464             # DumpRenderTrees to free it up. If we're running more than
 465             # one DumpRenderTree thread, we'll end up killing the other
 466             # DumpRenderTrees too, introducing spurious crashes. We accept
 467             # that tradeoff in order to avoid losing the rest of this
 468             # thread's results.
 469             _log.error('Test thread hung: killing all DumpRenderTrees')
 470             if worker._driver:
 471                 worker._driver.stop()
 472
 473         try:
 474             result = worker.get_test_result()
 475         except AttributeError, e:
 476             # This gets raised if the worker thread has already exited.
 477             failures = []
 478             _log.error('Cannot get results of test: %s' %
 479                        test_input.filename)
 480             result = test_results.TestResult(test_input.filename, failures=[],
 481                 test_run_time=0, total_time_for_all_diffs=0, time_for_diffs=0)
 482
 483         return result
 484
 485     def _run_test(self, test_input):
 486         """Run a single test file using a shared DumpRenderTree process.
 487
 488         Args:
 489           test_input: Object containing the test filename, uri and timeout
 490
 491         Returns: a TestResult object.
 492         """
 493         self._ensure_dump_render_tree_is_running()
 494         thread_timeout = _milliseconds_to_seconds(
 495              _pad_timeout(int(test_input.timeout)))
 496         self._next_timeout = time.time() + thread_timeout
 497         test_result = _run_single_test(self._port, self._options, test_input,
 498                                        self._test_types, self._test_args,
 499                                        self._driver)
 500         self._test_results.append(test_result)
 501         return test_result
 502
 503     def _ensure_dump_render_tree_is_running(self):
 504         """Start the shared DumpRenderTree, if it's not running.
 505
 506         This is not for use when running tests singly, since those each start
 507         a separate DumpRenderTree in their own thread.
 508
 509         """
 510         # poll() is not threadsafe and can throw OSError due to:
 511         # http://bugs.python.org/issue1731717
 512         if (not self._driver or self._driver.poll() is not None):
 513             self._driver = self._port.create_driver(self._test_args.png_path,
 514                                                     self._options)
 515             self._driver.start()
 516
 517     def _start_servers_with_lock(self):
 518         """Acquire http lock and start the servers."""
 519         self._http_lock_wait_begin = time.time()
 520         _log.debug('Acquire http lock ...')
 521         self._port.acquire_http_lock()
 522         _log.debug('Starting HTTP server ...')
 523         self._port.start_http_server()
 524         _log.debug('Starting WebSocket server ...')
 525         self._port.start_websocket_server()
 526         self._http_lock_wait_end = time.time()
 527         self._have_http_lock = True
 528
 529     def _stop_servers_with_lock(self):
 530         """Stop the servers and release http lock."""
 531         if self._have_http_lock:
 532             _log.debug('Stopping HTTP server ...')
 533             self._port.stop_http_server()
 534             _log.debug('Stopping WebSocket server ...')
 535             self._port.stop_websocket_server()
 536             _log.debug('Release http lock ...')
 537             self._port.release_http_lock()
 538             self._have_http_lock = False
 539
 540     def _kill_dump_render_tree(self):
 541         """Kill the DumpRenderTree process if it's running."""
 542         if self._driver:
 543             self._driver.stop()
 544             self._driver = None