703f9deee778c07403f0eb6e1c94f29e8afe6a06
[WebKit-https.git] / 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 import traceback
52
53 import test_failures
54 import test_results
55
56 _log = logging.getLogger("webkitpy.layout_tests.layout_package."
57                          "dump_render_tree_thread")
58
59
60 def find_thread_stack(id):
61     """Returns a stack object that can be used to dump a stack trace for
62     the given thread id (or None if the id is not found)."""
63     for thread_id, stack in sys._current_frames().items():
64         if thread_id == id:
65             return stack
66     return None
67
68
69 def log_stack(stack):
70     """Log a stack trace to log.error()."""
71     for filename, lineno, name, line in traceback.extract_stack(stack):
72         _log.error('File: "%s", line %d, in %s' % (filename, lineno, name))
73         if line:
74             _log.error('  %s' % line.strip())
75
76
77 def _process_output(port, options, test_input, test_types, test_args,
78                     crash, timeout, test_run_time, actual_checksum,
79                     output, error):
80     """Receives the output from a DumpRenderTree process, subjects it to a
81     number of tests, and returns a list of failure types the test produced.
82
83     Args:
84       port: port-specific hooks
85       options: command line options argument from optparse
86       proc: an active DumpRenderTree process
87       test_input: Object containing the test filename, uri and timeout
88       test_types: list of test types to subject the output to
89       test_args: arguments to be passed to each test
90
91     Returns: a TestResult object
92     """
93     failures = []
94
95     # Some test args, such as the image hash, may be added or changed on a
96     # test-by-test basis.
97     local_test_args = copy.copy(test_args)
98
99     local_test_args.hash = actual_checksum
100
101     if crash:
102         failures.append(test_failures.FailureCrash())
103     if timeout:
104         failures.append(test_failures.FailureTimeout())
105
106     if crash:
107         _log.debug("Stacktrace for %s:\n%s" % (test_input.filename, error))
108         # Strip off "file://" since RelativeTestFilename expects
109         # filesystem paths.
110         filename = os.path.join(options.results_directory,
111                                 port.relative_test_filename(
112                                 test_input.filename))
113         filename = os.path.splitext(filename)[0] + "-stack.txt"
114         port.maybe_make_directory(os.path.split(filename)[0])
115         with codecs.open(filename, "wb", "utf-8") as file:
116             file.write(error)
117     elif error:
118         _log.debug("Previous test output stderr lines:\n%s" % error)
119
120     # Check the output and save the results.
121     start_time = time.time()
122     time_for_diffs = {}
123     for test_type in test_types:
124         start_diff_time = time.time()
125         new_failures = test_type.compare_output(port, test_input.filename,
126                                                 output, local_test_args,
127                                                 options.configuration)
128         # Don't add any more failures if we already have a crash, so we don't
129         # double-report those tests. We do double-report for timeouts since
130         # we still want to see the text and image output.
131         if not crash:
132             failures.extend(new_failures)
133         time_for_diffs[test_type.__class__.__name__] = (
134             time.time() - start_diff_time)
135
136     total_time_for_all_diffs = time.time() - start_diff_time
137     return test_results.TestResult(test_input.filename, failures, test_run_time,
138                                    total_time_for_all_diffs, time_for_diffs)
139
140
141 def _pad_timeout(timeout):
142     """Returns a safe multiple of the per-test timeout value to use
143     to detect hung test threads.
144
145     """
146     # When we're running one test per DumpRenderTree process, we can
147     # enforce a hard timeout.  The DumpRenderTree watchdog uses 2.5x
148     # the timeout; we want to be larger than that.
149     return timeout * 3
150
151
152 def _milliseconds_to_seconds(msecs):
153     return float(msecs) / 1000.0
154
155
156 def _should_fetch_expected_checksum(options):
157     return options.pixel_tests and not (options.new_baseline or options.reset_results)
158
159
160 class SingleTestThread(threading.Thread):
161     """Thread wrapper for running a single test file."""
162
163     def __init__(self, port, options, test_input, test_types, test_args):
164         """
165         Args:
166           port: object implementing port-specific hooks
167           options: command line argument object from optparse
168           test_input: Object containing the test filename, uri and timeout
169           test_types: A list of TestType objects to run the test output
170               against.
171           test_args: A TestArguments object to pass to each TestType.
172         """
173
174         threading.Thread.__init__(self)
175         self._port = port
176         self._options = options
177         self._test_input = test_input
178         self._test_types = test_types
179         self._test_args = test_args
180         self._driver = None
181
182     def run(self):
183         self._covered_run()
184
185     def _covered_run(self):
186         # FIXME: this is a separate routine to work around a bug
187         # in coverage: see http://bitbucket.org/ned/coveragepy/issue/85.
188
189         # FIXME: Pull this into TestShellThread._run().
190         test_input = self._test_input
191         test_input.uri = self._port.filename_to_uri(test_input.filename)
192         if _should_fetch_expected_checksum(self._options):
193             test_input.image_checksum = self._port.expected_checksum(test_input.filename)
194
195         start = time.time()
196         self._driver = self._port.create_driver(self._test_args.png_path,
197                                                 self._options)
198         self._driver.start()
199         crash, timeout, actual_checksum, output, error = \
200             self._driver.run_test(test_input.uri, test_input.timeout,
201                                   test_input.image_checksum)
202         end = time.time()
203         self._test_result = _process_output(self._port, self._options,
204             test_input, self._test_types, self._test_args,
205             crash, timeout, end - start,
206             actual_checksum, output, error)
207         self._driver.stop()
208
209     def get_test_result(self):
210         return self._test_result
211
212
213 class WatchableThread(threading.Thread):
214     """This class abstracts an interface used by
215     run_webkit_tests.TestRunner._wait_for_threads_to_finish for thread
216     management."""
217     def __init__(self):
218         threading.Thread.__init__(self)
219         self._canceled = False
220         self._exception_info = None
221         self._next_timeout = None
222         self._thread_id = None
223
224     def cancel(self):
225         """Set a flag telling this thread to quit."""
226         self._canceled = True
227
228     def clear_next_timeout(self):
229         """Mark a flag telling this thread to stop setting timeouts."""
230         self._timeout = 0
231
232     def exception_info(self):
233         """If run() terminated on an uncaught exception, return it here
234         ((type, value, traceback) tuple).
235         Returns None if run() terminated normally. Meant to be called after
236         joining this thread."""
237         return self._exception_info
238
239     def id(self):
240         """Return a thread identifier."""
241         return self._thread_id
242
243     def next_timeout(self):
244         """Return the time the test is supposed to finish by."""
245         return self._next_timeout
246
247
248 class TestShellThread(WatchableThread):
249     def __init__(self, port, options, filename_list_queue, result_queue,
250                  test_types, test_args):
251         """Initialize all the local state for this DumpRenderTree thread.
252
253         Args:
254           port: interface to port-specific hooks
255           options: command line options argument from optparse
256           filename_list_queue: A thread safe Queue class that contains lists
257               of tuples of (filename, uri) pairs.
258           result_queue: A thread safe Queue class that will contain
259               serialized TestResult objects.
260           test_types: A list of TestType objects to run the test output
261               against.
262           test_args: A TestArguments object to pass to each TestType.
263         """
264         WatchableThread.__init__(self)
265         self._port = port
266         self._options = options
267         self._filename_list_queue = filename_list_queue
268         self._result_queue = result_queue
269         self._filename_list = []
270         self._test_types = test_types
271         self._test_args = test_args
272         self._driver = None
273         self._test_group_timing_stats = {}
274         self._test_results = []
275         self._num_tests = 0
276         self._start_time = 0
277         self._stop_time = 0
278         self._have_http_lock = False
279         self._http_lock_wait_begin = 0
280         self._http_lock_wait_end = 0
281
282         # Current group of tests we're running.
283         self._current_group = None
284         # Number of tests in self._current_group.
285         self._num_tests_in_current_group = None
286         # Time at which we started running tests from self._current_group.
287         self._current_group_start_time = None
288
289     def get_test_group_timing_stats(self):
290         """Returns a dictionary mapping test group to a tuple of
291         (number of tests in that group, time to run the tests)"""
292         return self._test_group_timing_stats
293
294     def get_test_results(self):
295         """Return the list of all tests run on this thread.
296
297         This is used to calculate per-thread statistics.
298
299         """
300         return self._test_results
301
302     def get_total_time(self):
303         return max(self._stop_time - self._start_time -
304                    self._http_lock_wait_time(), 0.0)
305
306     def get_num_tests(self):
307         return self._num_tests
308
309     def run(self):
310         """Delegate main work to a helper method and watch for uncaught
311         exceptions."""
312         self._covered_run()
313
314     def _covered_run(self):
315         # FIXME: this is a separate routine to work around a bug
316         # in coverage: see http://bitbucket.org/ned/coveragepy/issue/85.
317         self._thread_id = thread.get_ident()
318         self._start_time = time.time()
319         self._num_tests = 0
320         try:
321             _log.debug('%s starting' % (self.getName()))
322             self._run(test_runner=None, result_summary=None)
323             _log.debug('%s done (%d tests)' % (self.getName(),
324                        self.get_num_tests()))
325         except KeyboardInterrupt:
326             self._exception_info = sys.exc_info()
327             _log.debug("%s interrupted" % self.getName())
328         except:
329             # Save the exception for our caller to see.
330             self._exception_info = sys.exc_info()
331             self._stop_time = time.time()
332             _log.error('%s dying, exception raised' % self.getName())
333
334         self._stop_time = time.time()
335
336     def run_in_main_thread(self, test_runner, result_summary):
337         """This hook allows us to run the tests from the main thread if
338         --num-test-shells==1, instead of having to always run two or more
339         threads. This allows us to debug the test harness without having to
340         do multi-threaded debugging."""
341         self._run(test_runner, result_summary)
342
343     def cancel(self):
344         """Clean up http lock and set a flag telling this thread to quit."""
345         self._stop_servers_with_lock()
346         WatchableThread.cancel(self)
347
348     def next_timeout(self):
349         """Return the time the test is supposed to finish by."""
350         if self._next_timeout:
351             return self._next_timeout + self._http_lock_wait_time()
352         return self._next_timeout
353
354     def _http_lock_wait_time(self):
355         """Return the time what http locking takes."""
356         if self._http_lock_wait_begin == 0:
357             return 0
358         if self._http_lock_wait_end == 0:
359             return time.time() - self._http_lock_wait_begin
360         return self._http_lock_wait_end - self._http_lock_wait_begin
361
362     def _run(self, test_runner, result_summary):
363         """Main work entry point of the thread. Basically we pull urls from the
364         filename queue and run the tests until we run out of urls.
365
366         If test_runner is not None, then we call test_runner.UpdateSummary()
367         with the results of each test."""
368         batch_size = self._options.batch_size
369         batch_count = 0
370
371         # Append tests we're running to the existing tests_run.txt file.
372         # This is created in run_webkit_tests.py:_PrepareListsAndPrintOutput.
373         tests_run_filename = os.path.join(self._options.results_directory,
374                                           "tests_run.txt")
375         tests_run_file = codecs.open(tests_run_filename, "a", "utf-8")
376
377         while True:
378             if self._canceled:
379                 _log.debug('Testing cancelled')
380                 tests_run_file.close()
381                 return
382
383             if len(self._filename_list) is 0:
384                 if self._current_group is not None:
385                     self._test_group_timing_stats[self._current_group] = \
386                         (self._num_tests_in_current_group,
387                          time.time() - self._current_group_start_time)
388
389                 try:
390                     self._current_group, self._filename_list = \
391                         self._filename_list_queue.get_nowait()
392                 except Queue.Empty:
393                     self._stop_servers_with_lock()
394                     self._kill_dump_render_tree()
395                     tests_run_file.close()
396                     return
397
398                 if self._current_group == "tests_to_http_lock":
399                     self._start_servers_with_lock()
400                 elif self._have_http_lock:
401                     self._stop_servers_with_lock()
402
403                 self._num_tests_in_current_group = len(self._filename_list)
404                 self._current_group_start_time = time.time()
405
406             test_input = self._filename_list.pop()
407
408             # We have a url, run tests.
409             batch_count += 1
410             self._num_tests += 1
411             if self._options.run_singly:
412                 result = self._run_test_singly(test_input)
413             else:
414                 result = self._run_test(test_input)
415
416             filename = test_input.filename
417             tests_run_file.write(filename + "\n")
418             if result.failures:
419                 # Check and kill DumpRenderTree if we need to.
420                 if len([1 for f in result.failures
421                         if f.should_kill_dump_render_tree()]):
422                     self._kill_dump_render_tree()
423                     # Reset the batch count since the shell just bounced.
424                     batch_count = 0
425                 # Print the error message(s).
426                 error_str = '\n'.join(['  ' + f.message() for
427                                        f in result.failures])
428                 _log.debug("%s %s failed:\n%s" % (self.getName(),
429                            self._port.relative_test_filename(filename),
430                            error_str))
431             else:
432                 _log.debug("%s %s passed" % (self.getName(),
433                            self._port.relative_test_filename(filename)))
434             self._result_queue.put(result.dumps())
435
436             if batch_size > 0 and batch_count >= batch_size:
437                 # Bounce the shell and reset count.
438                 self._kill_dump_render_tree()
439                 batch_count = 0
440
441             if test_runner:
442                 test_runner.update_summary(result_summary)
443
444     def _run_test_singly(self, test_input):
445         """Run a test in a separate thread, enforcing a hard time limit.
446
447         Since we can only detect the termination of a thread, not any internal
448         state or progress, we can only run per-test timeouts when running test
449         files singly.
450
451         Args:
452           test_input: Object containing the test filename, uri and timeout
453
454         Returns:
455           A TestResult
456
457         """
458         worker = SingleTestThread(self._port,
459                                   self._options,
460                                   test_input,
461                                   self._test_types,
462                                   self._test_args)
463
464         worker.start()
465
466         thread_timeout = _milliseconds_to_seconds(
467             _pad_timeout(int(test_input.timeout)))
468         thread._next_timeout = time.time() + thread_timeout
469         worker.join(thread_timeout)
470         if worker.isAlive():
471             # If join() returned with the thread still running, the
472             # DumpRenderTree is completely hung and there's nothing
473             # more we can do with it.  We have to kill all the
474             # DumpRenderTrees to free it up. If we're running more than
475             # one DumpRenderTree thread, we'll end up killing the other
476             # DumpRenderTrees too, introducing spurious crashes. We accept
477             # that tradeoff in order to avoid losing the rest of this
478             # thread's results.
479             _log.error('Test thread hung: killing all DumpRenderTrees')
480             if worker._driver:
481                 worker._driver.stop()
482
483         try:
484             result = worker.get_test_result()
485         except AttributeError, e:
486             # This gets raised if the worker thread has already exited.
487             failures = []
488             _log.error('Cannot get results of test: %s' %
489                        test_input.filename)
490             result = test_results.TestResult(test_input.filename, failures=[],
491                 test_run_time=0, total_time_for_all_diffs=0, time_for_diffs=0)
492
493         return result
494
495     def _run_test(self, test_input):
496         """Run a single test file using a shared DumpRenderTree process.
497
498         Args:
499           test_input: Object containing the test filename, uri and timeout
500
501         Returns: a TestResult object.
502         """
503         self._ensure_dump_render_tree_is_running()
504         # The pixel_hash is used to avoid doing an image dump if the
505         # checksums match, so it should be set to a blank value if we
506         # are generating a new baseline.  (Otherwise, an image from a
507         # previous run will be copied into the baseline.)
508
509         # FIXME: Pull this into TestShellThread._run().
510         test_input.uri = self._port.filename_to_uri(test_input.filename)
511         if _should_fetch_expected_checksum(self._options):
512             test_input.image_checksum = self._port.expected_checksum(test_input.filename)
513         start = time.time()
514
515         thread_timeout = _milliseconds_to_seconds(
516              _pad_timeout(int(test_input.timeout)))
517         self._next_timeout = start + thread_timeout
518
519         crash, timeout, actual_checksum, output, error = \
520            self._driver.run_test(test_input.uri, test_input.timeout, test_input.image_checksum)
521         end = time.time()
522
523         result = _process_output(self._port, self._options,
524                                  test_input, self._test_types,
525                                  self._test_args, crash,
526                                  timeout, end - start, actual_checksum,
527                                  output, error)
528         self._test_results.append(result)
529         return result
530
531     def _ensure_dump_render_tree_is_running(self):
532         """Start the shared DumpRenderTree, if it's not running.
533
534         This is not for use when running tests singly, since those each start
535         a separate DumpRenderTree in their own thread.
536
537         """
538         # poll() is not threadsafe and can throw OSError due to:
539         # http://bugs.python.org/issue1731717
540         if (not self._driver or self._driver.poll() is not None):
541             self._driver = self._port.create_driver(self._test_args.png_path,
542                                                     self._options)
543             self._driver.start()
544
545     def _start_servers_with_lock(self):
546         """Acquire http lock and start the servers."""
547         self._http_lock_wait_begin = time.time()
548         _log.debug('Acquire http lock ...')
549         self._port.acquire_http_lock()
550         _log.debug('Starting HTTP server ...')
551         self._port.start_http_server()
552         _log.debug('Starting WebSocket server ...')
553         self._port.start_websocket_server()
554         self._http_lock_wait_end = time.time()
555         self._have_http_lock = True
556
557     def _stop_servers_with_lock(self):
558         """Stop the servers and release http lock."""
559         if self._have_http_lock:
560             _log.debug('Stopping HTTP server ...')
561             self._port.stop_http_server()
562             _log.debug('Stopping WebSocket server ...')
563             self._port.stop_websocket_server()
564             _log.debug('Release http lock ...')
565             self._port.release_http_lock()
566             self._have_http_lock = False
567
568     def _kill_dump_render_tree(self):
569         """Kill the DumpRenderTree process if it's running."""
570         if self._driver:
571             self._driver.stop()
572             self._driver = None