| OLD | NEW |
| (Empty) |
| 1 # Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. | |
| 2 # Use of this source code is governed by a BSD-style license that can be | |
| 3 # found in the LICENSE file. | |
| 4 | |
| 5 """A Thread object for running the test shell and processing URLs from a | |
| 6 shared queue. | |
| 7 | |
| 8 Each thread runs a separate instance of the test_shell binary and validates | |
| 9 the output. When there are no more URLs to process in the shared queue, the | |
| 10 thread exits. | |
| 11 """ | |
| 12 | |
| 13 import copy | |
| 14 import logging | |
| 15 import os | |
| 16 import Queue | |
| 17 import signal | |
| 18 import subprocess | |
| 19 import sys | |
| 20 import thread | |
| 21 import threading | |
| 22 import time | |
| 23 | |
| 24 import path_utils | |
| 25 import test_failures | |
| 26 | |
| 27 | |
| 28 def ProcessOutput(proc, test_info, test_types, test_args, target, output_dir): | |
| 29 """Receives the output from a test_shell process, subjects it to a number | |
| 30 of tests, and returns a list of failure types the test produced. | |
| 31 | |
| 32 Args: | |
| 33 proc: an active test_shell process | |
| 34 test_info: Object containing the test filename, uri and timeout | |
| 35 test_types: list of test types to subject the output to | |
| 36 test_args: arguments to be passed to each test | |
| 37 target: Debug or Release | |
| 38 output_dir: directory to put crash stack traces into | |
| 39 | |
| 40 Returns: a list of failure objects and times for the test being processed | |
| 41 """ | |
| 42 outlines = [] | |
| 43 extra_lines = [] | |
| 44 failures = [] | |
| 45 crash = False | |
| 46 | |
| 47 # Some test args, such as the image hash, may be added or changed on a | |
| 48 # test-by-test basis. | |
| 49 local_test_args = copy.copy(test_args) | |
| 50 | |
| 51 start_time = time.time() | |
| 52 | |
| 53 line = proc.stdout.readline() | |
| 54 | |
| 55 # Only start saving output lines once we've loaded the URL for the test. | |
| 56 url = None | |
| 57 test_string = test_info.uri.strip() | |
| 58 | |
| 59 while line.rstrip() != "#EOF": | |
| 60 # Make sure we haven't crashed. | |
| 61 if line == '' and proc.poll() is not None: | |
| 62 failures.append(test_failures.FailureCrash()) | |
| 63 | |
| 64 # This is hex code 0xc000001d, which is used for abrupt | |
| 65 # termination. This happens if we hit ctrl+c from the prompt and | |
| 66 # we happen to be waiting on the test_shell. | |
| 67 # sdoyon: Not sure for which OS and in what circumstances the | |
| 68 # above code is valid. What works for me under Linux to detect | |
| 69 # ctrl+c is for the subprocess returncode to be negative SIGINT. | |
| 70 # And that agrees with the subprocess documentation. | |
| 71 if (-1073741510 == proc.returncode or | |
| 72 - signal.SIGINT == proc.returncode): | |
| 73 raise KeyboardInterrupt | |
| 74 crash = True | |
| 75 break | |
| 76 | |
| 77 # Don't include #URL lines in our output | |
| 78 if line.startswith("#URL:"): | |
| 79 url = line.rstrip()[5:] | |
| 80 if url != test_string: | |
| 81 logging.fatal("Test got out of sync:\n|%s|\n|%s|" % | |
| 82 (url, test_string)) | |
| 83 raise AssertionError("test out of sync") | |
| 84 elif line.startswith("#MD5:"): | |
| 85 local_test_args.hash = line.rstrip()[5:] | |
| 86 elif line.startswith("#TEST_TIMED_OUT"): | |
| 87 # Test timed out, but we still need to read until #EOF. | |
| 88 failures.append(test_failures.FailureTimeout()) | |
| 89 elif url: | |
| 90 outlines.append(line) | |
| 91 else: | |
| 92 extra_lines.append(line) | |
| 93 | |
| 94 line = proc.stdout.readline() | |
| 95 | |
| 96 end_test_time = time.time() | |
| 97 | |
| 98 if len(extra_lines): | |
| 99 extra = "".join(extra_lines) | |
| 100 if crash: | |
| 101 logging.debug("Stacktrace for %s:\n%s" % (test_string, extra)) | |
| 102 # Strip off "file://" since RelativeTestFilename expects | |
| 103 # filesystem paths. | |
| 104 filename = os.path.join(output_dir, | |
| 105 path_utils.RelativeTestFilename(test_string[7:])) | |
| 106 filename = os.path.splitext(filename)[0] + "-stack.txt" | |
| 107 path_utils.MaybeMakeDirectory(os.path.split(filename)[0]) | |
| 108 open(filename, "wb").write(extra) | |
| 109 else: | |
| 110 logging.debug("Previous test output extra lines after dump:\n%s" % | |
| 111 extra) | |
| 112 | |
| 113 # Check the output and save the results. | |
| 114 time_for_diffs = {} | |
| 115 for test_type in test_types: | |
| 116 start_diff_time = time.time() | |
| 117 new_failures = test_type.CompareOutput(test_info.filename, | |
| 118 proc, | |
| 119 ''.join(outlines), | |
| 120 local_test_args, | |
| 121 target) | |
| 122 # Don't add any more failures if we already have a crash, so we don't | |
| 123 # double-report those tests. We do double-report for timeouts since | |
| 124 # we still want to see the text and image output. | |
| 125 if not crash: | |
| 126 failures.extend(new_failures) | |
| 127 time_for_diffs[test_type.__class__.__name__] = ( | |
| 128 time.time() - start_diff_time) | |
| 129 | |
| 130 total_time_for_all_diffs = time.time() - end_test_time | |
| 131 test_run_time = end_test_time - start_time | |
| 132 return TestStats(test_info.filename, failures, test_run_time, | |
| 133 total_time_for_all_diffs, time_for_diffs) | |
| 134 | |
| 135 | |
| 136 def StartTestShell(command, args): | |
| 137 """Returns the process for a new test_shell started in layout-tests mode. | |
| 138 """ | |
| 139 cmd = [] | |
| 140 # Hook for injecting valgrind or other runtime instrumentation, | |
| 141 # used by e.g. tools/valgrind/valgrind_tests.py. | |
| 142 wrapper = os.environ.get("BROWSER_WRAPPER", None) | |
| 143 if wrapper != None: | |
| 144 cmd += [wrapper] | |
| 145 cmd += command + ['--layout-tests'] + args | |
| 146 return subprocess.Popen(cmd, | |
| 147 stdin=subprocess.PIPE, | |
| 148 stdout=subprocess.PIPE, | |
| 149 stderr=subprocess.STDOUT) | |
| 150 | |
| 151 | |
| 152 class TestStats: | |
| 153 | |
| 154 def __init__(self, filename, failures, test_run_time, | |
| 155 total_time_for_all_diffs, time_for_diffs): | |
| 156 self.filename = filename | |
| 157 self.failures = failures | |
| 158 self.test_run_time = test_run_time | |
| 159 self.total_time_for_all_diffs = total_time_for_all_diffs | |
| 160 self.time_for_diffs = time_for_diffs | |
| 161 | |
| 162 | |
| 163 class SingleTestThread(threading.Thread): | |
| 164 """Thread wrapper for running a single test file.""" | |
| 165 | |
| 166 def __init__(self, test_shell_command, shell_args, test_info, test_types, | |
| 167 test_args, target, output_dir): | |
| 168 """ | |
| 169 Args: | |
| 170 test_info: Object containing the test filename, uri and timeout | |
| 171 output_dir: Directory to put crash stacks into. | |
| 172 See TestShellThread for documentation of the remaining arguments. | |
| 173 """ | |
| 174 | |
| 175 threading.Thread.__init__(self) | |
| 176 self._command = test_shell_command | |
| 177 self._shell_args = shell_args | |
| 178 self._test_info = test_info | |
| 179 self._test_types = test_types | |
| 180 self._test_args = test_args | |
| 181 self._target = target | |
| 182 self._output_dir = output_dir | |
| 183 | |
| 184 def run(self): | |
| 185 proc = StartTestShell(self._command, self._shell_args + | |
| 186 ["--time-out-ms=" + self._test_info.timeout, self._test_info.uri]) | |
| 187 self._test_stats = ProcessOutput(proc, self._test_info, | |
| 188 self._test_types, self._test_args, self._target, self._output_dir) | |
| 189 | |
| 190 def GetTestStats(self): | |
| 191 return self._test_stats | |
| 192 | |
| 193 | |
| 194 class TestShellThread(threading.Thread): | |
| 195 | |
| 196 def __init__(self, filename_list_queue, result_queue, test_shell_command, | |
| 197 test_types, test_args, shell_args, options): | |
| 198 """Initialize all the local state for this test shell thread. | |
| 199 | |
| 200 Args: | |
| 201 filename_list_queue: A thread safe Queue class that contains lists | |
| 202 of tuples of (filename, uri) pairs. | |
| 203 result_queue: A thread safe Queue class that will contain tuples of | |
| 204 (test, failure lists) for the test results. | |
| 205 test_shell_command: A list specifying the command+args for | |
| 206 test_shell | |
| 207 test_types: A list of TestType objects to run the test output | |
| 208 against. | |
| 209 test_args: A TestArguments object to pass to each TestType. | |
| 210 shell_args: Any extra arguments to be passed to test_shell.exe. | |
| 211 options: A property dictionary as produced by optparse. The | |
| 212 command-line options should match those expected by | |
| 213 run_webkit_tests; they are typically passed via the | |
| 214 run_webkit_tests.TestRunner class.""" | |
| 215 threading.Thread.__init__(self) | |
| 216 self._filename_list_queue = filename_list_queue | |
| 217 self._result_queue = result_queue | |
| 218 self._filename_list = [] | |
| 219 self._test_shell_command = test_shell_command | |
| 220 self._test_types = test_types | |
| 221 self._test_args = test_args | |
| 222 self._test_shell_proc = None | |
| 223 self._shell_args = shell_args | |
| 224 self._options = options | |
| 225 self._canceled = False | |
| 226 self._exception_info = None | |
| 227 self._directory_timing_stats = {} | |
| 228 self._test_stats = [] | |
| 229 self._num_tests = 0 | |
| 230 self._start_time = 0 | |
| 231 self._stop_time = 0 | |
| 232 | |
| 233 # Current directory of tests we're running. | |
| 234 self._current_dir = None | |
| 235 # Number of tests in self._current_dir. | |
| 236 self._num_tests_in_current_dir = None | |
| 237 # Time at which we started running tests from self._current_dir. | |
| 238 self._current_dir_start_time = None | |
| 239 | |
| 240 def GetDirectoryTimingStats(self): | |
| 241 """Returns a dictionary mapping test directory to a tuple of | |
| 242 (number of tests in that directory, time to run the tests)""" | |
| 243 return self._directory_timing_stats | |
| 244 | |
| 245 def GetIndividualTestStats(self): | |
| 246 """Returns a list of (test_filename, time_to_run_test, | |
| 247 total_time_for_all_diffs, time_for_diffs) tuples.""" | |
| 248 return self._test_stats | |
| 249 | |
| 250 def Cancel(self): | |
| 251 """Set a flag telling this thread to quit.""" | |
| 252 self._canceled = True | |
| 253 | |
| 254 def GetExceptionInfo(self): | |
| 255 """If run() terminated on an uncaught exception, return it here | |
| 256 ((type, value, traceback) tuple). | |
| 257 Returns None if run() terminated normally. Meant to be called after | |
| 258 joining this thread.""" | |
| 259 return self._exception_info | |
| 260 | |
| 261 def GetTotalTime(self): | |
| 262 return max(self._stop_time - self._start_time, 0.0) | |
| 263 | |
| 264 def GetNumTests(self): | |
| 265 return self._num_tests | |
| 266 | |
| 267 def run(self): | |
| 268 """Delegate main work to a helper method and watch for uncaught | |
| 269 exceptions.""" | |
| 270 self._start_time = time.time() | |
| 271 self._num_tests = 0 | |
| 272 try: | |
| 273 logging.debug('%s starting' % (self.getName())) | |
| 274 self._Run(test_runner=None, result_summary=None) | |
| 275 logging.debug('%s done (%d tests)' % (self.getName(), | |
| 276 self.GetNumTests())) | |
| 277 except: | |
| 278 # Save the exception for our caller to see. | |
| 279 self._exception_info = sys.exc_info() | |
| 280 self._stop_time = time.time() | |
| 281 # Re-raise it and die. | |
| 282 logging.error('%s dying: %s' % (self.getName(), | |
| 283 self._exception_info)) | |
| 284 raise | |
| 285 self._stop_time = time.time() | |
| 286 | |
| 287 def RunInMainThread(self, test_runner, result_summary): | |
| 288 """This hook allows us to run the tests from the main thread if | |
| 289 --num-test-shells==1, instead of having to always run two or more | |
| 290 threads. This allows us to debug the test harness without having to | |
| 291 do multi-threaded debugging.""" | |
| 292 self._Run(test_runner, result_summary) | |
| 293 | |
| 294 def _Run(self, test_runner, result_summary): | |
| 295 """Main work entry point of the thread. Basically we pull urls from the | |
| 296 filename queue and run the tests until we run out of urls. | |
| 297 | |
| 298 If test_runner is not None, then we call test_runner.UpdateSummary() | |
| 299 with the results of each test.""" | |
| 300 batch_size = 0 | |
| 301 batch_count = 0 | |
| 302 if self._options.batch_size: | |
| 303 try: | |
| 304 batch_size = int(self._options.batch_size) | |
| 305 except: | |
| 306 logging.info("Ignoring invalid batch size '%s'" % | |
| 307 self._options.batch_size) | |
| 308 | |
| 309 # Append tests we're running to the existing tests_run.txt file. | |
| 310 # This is created in run_webkit_tests.py:_PrepareListsAndPrintOutput. | |
| 311 tests_run_filename = os.path.join(self._options.results_directory, | |
| 312 "tests_run.txt") | |
| 313 tests_run_file = open(tests_run_filename, "a") | |
| 314 | |
| 315 while True: | |
| 316 if self._canceled: | |
| 317 logging.info('Testing canceled') | |
| 318 tests_run_file.close() | |
| 319 return | |
| 320 | |
| 321 if len(self._filename_list) is 0: | |
| 322 if self._current_dir is not None: | |
| 323 self._directory_timing_stats[self._current_dir] = \ | |
| 324 (self._num_tests_in_current_dir, | |
| 325 time.time() - self._current_dir_start_time) | |
| 326 | |
| 327 try: | |
| 328 self._current_dir, self._filename_list = \ | |
| 329 self._filename_list_queue.get_nowait() | |
| 330 except Queue.Empty: | |
| 331 self._KillTestShell() | |
| 332 tests_run_file.close() | |
| 333 return | |
| 334 | |
| 335 self._num_tests_in_current_dir = len(self._filename_list) | |
| 336 self._current_dir_start_time = time.time() | |
| 337 | |
| 338 test_info = self._filename_list.pop() | |
| 339 | |
| 340 # We have a url, run tests. | |
| 341 batch_count += 1 | |
| 342 self._num_tests += 1 | |
| 343 if self._options.run_singly: | |
| 344 failures = self._RunTestSingly(test_info) | |
| 345 else: | |
| 346 failures = self._RunTest(test_info) | |
| 347 | |
| 348 filename = test_info.filename | |
| 349 tests_run_file.write(filename + "\n") | |
| 350 if failures: | |
| 351 # Check and kill test shell if we need too. | |
| 352 if len([1 for f in failures if f.ShouldKillTestShell()]): | |
| 353 self._KillTestShell() | |
| 354 # Reset the batch count since the shell just bounced. | |
| 355 batch_count = 0 | |
| 356 # Print the error message(s). | |
| 357 error_str = '\n'.join([' ' + f.Message() for f in failures]) | |
| 358 logging.debug("%s %s failed:\n%s" % (self.getName(), | |
| 359 path_utils.RelativeTestFilename(filename), | |
| 360 error_str)) | |
| 361 else: | |
| 362 logging.debug("%s %s passed" % (self.getName(), | |
| 363 path_utils.RelativeTestFilename(filename))) | |
| 364 self._result_queue.put((filename, failures)) | |
| 365 | |
| 366 if batch_size > 0 and batch_count > batch_size: | |
| 367 # Bounce the shell and reset count. | |
| 368 self._KillTestShell() | |
| 369 batch_count = 0 | |
| 370 | |
| 371 if test_runner: | |
| 372 test_runner.UpdateSummary(result_summary) | |
| 373 | |
| 374 def _RunTestSingly(self, test_info): | |
| 375 """Run a test in a separate thread, enforcing a hard time limit. | |
| 376 | |
| 377 Since we can only detect the termination of a thread, not any internal | |
| 378 state or progress, we can only run per-test timeouts when running test | |
| 379 files singly. | |
| 380 | |
| 381 Args: | |
| 382 test_info: Object containing the test filename, uri and timeout | |
| 383 | |
| 384 Return: | |
| 385 A list of TestFailure objects describing the error. | |
| 386 """ | |
| 387 worker = SingleTestThread(self._test_shell_command, | |
| 388 self._shell_args, | |
| 389 test_info, | |
| 390 self._test_types, | |
| 391 self._test_args, | |
| 392 self._options.target, | |
| 393 self._options.results_directory) | |
| 394 | |
| 395 worker.start() | |
| 396 | |
| 397 # When we're running one test per test_shell process, we can enforce | |
| 398 # a hard timeout. the test_shell watchdog uses 2.5x the timeout | |
| 399 # We want to be larger than that. | |
| 400 worker.join(int(test_info.timeout) * 3.0 / 1000.0) | |
| 401 if worker.isAlive(): | |
| 402 # If join() returned with the thread still running, the | |
| 403 # test_shell.exe is completely hung and there's nothing | |
| 404 # more we can do with it. We have to kill all the | |
| 405 # test_shells to free it up. If we're running more than | |
| 406 # one test_shell thread, we'll end up killing the other | |
| 407 # test_shells too, introducing spurious crashes. We accept that | |
| 408 # tradeoff in order to avoid losing the rest of this thread's | |
| 409 # results. | |
| 410 logging.error('Test thread hung: killing all test_shells') | |
| 411 path_utils.KillAllTestShells() | |
| 412 | |
| 413 try: | |
| 414 stats = worker.GetTestStats() | |
| 415 self._test_stats.append(stats) | |
| 416 failures = stats.failures | |
| 417 except AttributeError, e: | |
| 418 failures = [] | |
| 419 logging.error('Cannot get results of test: %s' % | |
| 420 test_info.filename) | |
| 421 | |
| 422 return failures | |
| 423 | |
| 424 def _RunTest(self, test_info): | |
| 425 """Run a single test file using a shared test_shell process. | |
| 426 | |
| 427 Args: | |
| 428 test_info: Object containing the test filename, uri and timeout | |
| 429 | |
| 430 Return: | |
| 431 A list of TestFailure objects describing the error. | |
| 432 """ | |
| 433 self._EnsureTestShellIsRunning() | |
| 434 # Args to test_shell is a space-separated list of | |
| 435 # "uri timeout pixel_hash" | |
| 436 # The timeout and pixel_hash are optional. The timeout is used if this | |
| 437 # test has a custom timeout. The pixel_hash is used to avoid doing an | |
| 438 # image dump if the checksums match, so it should be set to a blank | |
| 439 # value if we are generating a new baseline. | |
| 440 # (Otherwise, an image from a previous run will be copied into | |
| 441 # the baseline.) | |
| 442 image_hash = test_info.image_hash | |
| 443 if image_hash and self._test_args.new_baseline: | |
| 444 image_hash = "" | |
| 445 self._test_shell_proc.stdin.write(("%s %s %s\n" % | |
| 446 (test_info.uri, test_info.timeout, image_hash))) | |
| 447 | |
| 448 # If the test shell is dead, the above may cause an IOError as we | |
| 449 # try to write onto the broken pipe. If this is the first test for | |
| 450 # this test shell process, than the test shell did not | |
| 451 # successfully start. If this is not the first test, then the | |
| 452 # previous tests have caused some kind of delayed crash. We don't | |
| 453 # try to recover here. | |
| 454 self._test_shell_proc.stdin.flush() | |
| 455 | |
| 456 stats = ProcessOutput(self._test_shell_proc, test_info, | |
| 457 self._test_types, self._test_args, | |
| 458 self._options.target, | |
| 459 self._options.results_directory) | |
| 460 | |
| 461 self._test_stats.append(stats) | |
| 462 return stats.failures | |
| 463 | |
| 464 def _EnsureTestShellIsRunning(self): | |
| 465 """Start the shared test shell, if it's not running. Not for use when | |
| 466 running tests singly, since those each start a separate test shell in | |
| 467 their own thread. | |
| 468 """ | |
| 469 if (not self._test_shell_proc or | |
| 470 self._test_shell_proc.poll() is not None): | |
| 471 self._test_shell_proc = StartTestShell(self._test_shell_command, | |
| 472 self._shell_args) | |
| 473 | |
| 474 def _KillTestShell(self): | |
| 475 """Kill the test shell process if it's running.""" | |
| 476 if self._test_shell_proc: | |
| 477 self._test_shell_proc.stdin.close() | |
| 478 self._test_shell_proc.stdout.close() | |
| 479 if self._test_shell_proc.stderr: | |
| 480 self._test_shell_proc.stderr.close() | |
| 481 if (sys.platform not in ('win32', 'cygwin') and | |
| 482 not self._test_shell_proc.poll()): | |
| 483 # Closing stdin/stdout/stderr hangs sometimes on OS X. | |
| 484 null = open(os.devnull, "w") | |
| 485 subprocess.Popen(["kill", "-9", | |
| 486 str(self._test_shell_proc.pid)], stderr=null) | |
| 487 null.close() | |
| 488 self._test_shell_proc = None | |
| OLD | NEW |