1 # Copyright (C) 2011 Google Inc. All rights reserved. 2 # 3 # Redistribution and use in source and binary forms, with or without 4 # modification, are permitted provided that the following conditions are 5 # met: 6 # 7 # * Redistributions of source code must retain the above copyright 8 # notice, this list of conditions and the following disclaimer. 9 # * Redistributions in binary form must reproduce the above 10 # copyright notice, this list of conditions and the following disclaimer 11 # in the documentation and/or other materials provided with the 12 # distribution. 13 # * Neither the Google name nor the names of its 14 # contributors may be used to endorse or promote products derived from 15 # this software without specific prior written permission. 16 # 17 # THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS 18 # "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT 19 # LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR 20 # A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT 21 # OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, 22 # SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT 23 # LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, 24 # DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY 25 # THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT 26 # (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE 27 # OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. 28 29 import base64 30 import copy 31 import logging 32 import re 33 import shlex 34 import sys 35 import time 36 import os 37 38 from webkitpy.common.system import path 39 from webkitpy.common.system.profiler import ProfilerFactory 40 41 42 _log = logging.getLogger(__name__) 43 44 45 DRIVER_START_TIMEOUT_SECS = 30 46 47 48 class DriverInput(object): 49 def __init__(self, test_name, timeout, image_hash, should_run_pixel_test, args): 50 self.test_name = test_name 51 self.timeout = timeout # in ms 52 self.image_hash = image_hash 53 self.should_run_pixel_test = should_run_pixel_test 54 self.args = args 55 56 57 class DriverOutput(object): 58 """Groups information about a output from driver for easy passing 59 and post-processing of data.""" 60 61 def __init__(self, text, image, image_hash, audio, crash=False, 62 test_time=0, measurements=None, timeout=False, error='', crashed_process_name='??', 63 crashed_pid=None, crash_log=None, leak=False, leak_log=None, pid=None): 64 # FIXME: Args could be renamed to better clarify what they do. 65 self.text = text 66 self.image = image # May be empty-string if the test crashes. 67 self.image_hash = image_hash 68 self.image_diff = None # image_diff gets filled in after construction. 69 self.audio = audio # Binary format is port-dependent. 70 self.crash = crash 71 self.crashed_process_name = crashed_process_name 72 self.crashed_pid = crashed_pid 73 self.crash_log = crash_log 74 self.leak = leak 75 self.leak_log = leak_log 76 self.test_time = test_time 77 self.measurements = measurements 78 self.timeout = timeout 79 self.error = error # stderr output 80 self.pid = pid 81 82 def has_stderr(self): 83 return bool(self.error) 84 85 86 class DeviceFailure(Exception): 87 pass 88 89 90 class Driver(object): 91 """object for running test(s) using content_shell or other driver.""" 92 93 def __init__(self, port, worker_number, pixel_tests, no_timeout=False): 94 """Initialize a Driver to subsequently run tests. 95 96 Typically this routine will spawn content_shell in a config 97 ready for subsequent input. 98 99 port - reference back to the port object. 100 worker_number - identifier for a particular worker/driver instance 101 """ 102 self._port = port 103 self._worker_number = worker_number 104 self._no_timeout = no_timeout 105 106 self._driver_tempdir = None 107 # content_shell can report back subprocess crashes by printing 108 # "#CRASHED - PROCESSNAME". Since those can happen at any time 109 # and ServerProcess won't be aware of them (since the actual tool 110 # didn't crash, just a subprocess) we record the crashed subprocess name here. 111 self._crashed_process_name = None 112 self._crashed_pid = None 113 114 # content_shell can report back subprocesses that became unresponsive 115 # This could mean they crashed. 116 self._subprocess_was_unresponsive = False 117 118 # content_shell can report back subprocess DOM-object leaks by printing 119 # "#LEAK". This leak detection is enabled only when the flag 120 # --enable-leak-detection is passed to content_shell. 121 self._leaked = False 122 123 # stderr reading is scoped on a per-test (not per-block) basis, so we store the accumulated 124 # stderr output, as well as if we've seen #EOF on this driver instance. 125 # FIXME: We should probably remove _read_first_block and _read_optional_image_block and 126 # instead scope these locally in run_test. 127 self.error_from_test = str() 128 self.err_seen_eof = False 129 self._server_process = None 130 self._current_cmd_line = None 131 132 self._measurements = {} 133 if self._port.get_option("profile"): 134 profiler_name = self._port.get_option("profiler") 135 self._profiler = ProfilerFactory.create_profiler(self._port.host, 136 self._port._path_to_driver(), self._port.results_directory(), profiler_name) 137 else: 138 self._profiler = None 139 140 def __del__(self): 141 self.stop() 142 143 def run_test(self, driver_input, stop_when_done): 144 """Run a single test and return the results. 145 146 Note that it is okay if a test times out or crashes and leaves 147 the driver in an indeterminate state. The upper layers of the program 148 are responsible for cleaning up and ensuring things are okay. 149 150 Returns a DriverOutput object. 151 """ 152 start_time = time.time() 153 stdin_deadline = start_time + int(driver_input.timeout) / 2000.0 154 self.start(driver_input.should_run_pixel_test, driver_input.args, stdin_deadline) 155 test_begin_time = time.time() 156 self.error_from_test = str() 157 self.err_seen_eof = False 158 159 command = self._command_from_driver_input(driver_input) 160 deadline = test_begin_time + int(driver_input.timeout) / 1000.0 161 162 self._server_process.write(command) 163 text, audio = self._read_first_block(deadline) # First block is either text or audio 164 image, actual_image_hash = self._read_optional_image_block(deadline) # The second (optional) block is image data. 165 166 crashed = self.has_crashed() 167 timed_out = self._server_process.timed_out 168 pid = self._server_process.pid() 169 leaked = self._leaked 170 171 if not crashed: 172 sanitizer = self._port._output_contains_sanitizer_messages(self.error_from_test) 173 if sanitizer: 174 self.error_from_test = 'OUTPUT CONTAINS "' + sanitizer + '", so we are treating this test as if it crashed, even though it did not.\n\n' + self.error_from_test 175 crashed = True 176 self._crashed_process_name = "unknown process name" 177 self._crashed_pid = 0 178 179 if stop_when_done or crashed or timed_out or leaked: 180 # We call stop() even if we crashed or timed out in order to get any remaining stdout/stderr output. 181 # In the timeout case, we kill the hung process as well. 182 out, err = self._server_process.stop(self._port.driver_stop_timeout() if stop_when_done else 0.0) 183 if out: 184 text += out 185 if err: 186 self.error_from_test += err 187 self._server_process = None 188 189 crash_log = None 190 if crashed: 191 self.error_from_test, crash_log = self._get_crash_log(text, self.error_from_test, newer_than=start_time) 192 193 # If we don't find a crash log use a placeholder error message instead. 194 if not crash_log: 195 pid_str = str(self._crashed_pid) if self._crashed_pid else "unknown pid" 196 crash_log = 'No crash log found for %s:%s.\n' % (self._crashed_process_name, pid_str) 197 # If we were unresponsive append a message informing there may not have been a crash. 198 if self._subprocess_was_unresponsive: 199 crash_log += 'Process failed to become responsive before timing out.\n' 200 201 # Print stdout and stderr to the placeholder crash log; we want as much context as possible. 202 if self.error_from_test: 203 crash_log += '\nstdout:\n%s\nstderr:\n%s\n' % (text, self.error_from_test) 204 205 return DriverOutput(text, image, actual_image_hash, audio, 206 crash=crashed, test_time=time.time() - test_begin_time, measurements=self._measurements, 207 timeout=timed_out, error=self.error_from_test, 208 crashed_process_name=self._crashed_process_name, 209 crashed_pid=self._crashed_pid, crash_log=crash_log, 210 leak=leaked, leak_log=self._leak_log, 211 pid=pid) 212 213 def _get_crash_log(self, stdout, stderr, newer_than): 214 return self._port._get_crash_log(self._crashed_process_name, self._crashed_pid, stdout, stderr, newer_than) 215 216 # FIXME: Seems this could just be inlined into callers. 217 @classmethod 218 def _command_wrapper(cls, wrapper_option): 219 # Hook for injecting valgrind or other runtime instrumentation, 220 # used by e.g. tools/valgrind/valgrind_tests.py. 221 return shlex.split(wrapper_option) if wrapper_option else [] 222 223 HTTP_DIR = "http/tests/" 224 HTTP_LOCAL_DIR = "http/tests/local/" 225 226 def is_http_test(self, test_name): 227 return test_name.startswith(self.HTTP_DIR) and not test_name.startswith(self.HTTP_LOCAL_DIR) 228 229 def test_to_uri(self, test_name): 230 """Convert a test name to a URI. 231 232 Tests which have an 'https' directory in their paths (e.g. 233 '/http/tests/security/mixedContent/https/test1.html') will be loaded 234 over HTTPS; all other tests over HTTP. 235 """ 236 if not self.is_http_test(test_name): 237 return path.abspath_to_uri(self._port.host.platform, self._port.abspath_for_test(test_name)) 238 239 relative_path = test_name[len(self.HTTP_DIR):] 240 241 if "/https/" in test_name: 242 return "https://127.0.0.1:8443/" + relative_path 243 return "http://127.0.0.1:8000/" + relative_path 244 245 def uri_to_test(self, uri): 246 """Return the base layout test name for a given URI. 247 248 This returns the test name for a given URI, e.g., if you passed in 249 "file:///src/LayoutTests/fast/html/keygen.html" it would return 250 "fast/html/keygen.html". 251 252 """ 253 if uri.startswith("file:///"): 254 prefix = path.abspath_to_uri(self._port.host.platform, self._port.layout_tests_dir()) 255 if not prefix.endswith('/'): 256 prefix += '/' 257 return uri[len(prefix):] 258 if uri.startswith("http://"): 259 return uri.replace('http://127.0.0.1:8000/', self.HTTP_DIR) 260 if uri.startswith("https://"): 261 return uri.replace('https://127.0.0.1:8443/', self.HTTP_DIR) 262 raise NotImplementedError('unknown url type: %s' % uri) 263 264 def has_crashed(self): 265 if self._server_process is None: 266 return False 267 if self._crashed_process_name: 268 return True 269 if self._server_process.has_crashed(): 270 self._crashed_process_name = self._server_process.name() 271 self._crashed_pid = self._server_process.pid() 272 return True 273 return False 274 275 def start(self, pixel_tests, per_test_args, deadline): 276 new_cmd_line = self.cmd_line(pixel_tests, per_test_args) 277 if not self._server_process or new_cmd_line != self._current_cmd_line: 278 self._start(pixel_tests, per_test_args) 279 self._run_post_start_tasks() 280 281 def _setup_environ_for_driver(self, environment): 282 if self._profiler: 283 environment = self._profiler.adjusted_environment(environment) 284 return environment 285 286 def _start(self, pixel_tests, per_test_args, wait_for_ready=True): 287 self.stop() 288 self._driver_tempdir = self._port._filesystem.mkdtemp(prefix='%s-' % self._port.driver_name()) 289 server_name = self._port.driver_name() 290 environment = self._port.setup_environ_for_server(server_name) 291 environment = self._setup_environ_for_driver(environment) 292 self._crashed_process_name = None 293 self._crashed_pid = None 294 self._leaked = False 295 self._leak_log = None 296 cmd_line = self.cmd_line(pixel_tests, per_test_args) 297 self._server_process = self._port._server_process_constructor(self._port, server_name, cmd_line, environment, logging=self._port.get_option("driver_logging")) 298 self._server_process.start() 299 self._current_cmd_line = cmd_line 300 301 if wait_for_ready: 302 deadline = time.time() + DRIVER_START_TIMEOUT_SECS 303 if not self._wait_for_server_process_output(self._server_process, deadline, '#READY'): 304 _log.error("content_shell took too long to startup.") 305 306 def _wait_for_server_process_output(self, server_process, deadline, text): 307 output = '' 308 line = server_process.read_stdout_line(deadline) 309 while not server_process.timed_out and not server_process.has_crashed() and not text in line.rstrip(): 310 output += line 311 line = server_process.read_stdout_line(deadline) 312 313 if server_process.timed_out or server_process.has_crashed(): 314 _log.error('Failed to start the %s process: \n%s' % (server_process.name(), output)) 315 return False 316 317 return True 318 319 def _run_post_start_tasks(self): 320 # Remote drivers may override this to delay post-start tasks until the server has ack'd. 321 if self._profiler: 322 self._profiler.attach_to_pid(self._pid_on_target()) 323 324 def _pid_on_target(self): 325 # Remote drivers will override this method to return the pid on the device. 326 return self._server_process.pid() 327 328 def stop(self, timeout_secs=0.0): 329 if self._server_process: 330 self._server_process.stop(timeout_secs) 331 self._server_process = None 332 if self._profiler: 333 self._profiler.profile_after_exit() 334 335 if self._driver_tempdir: 336 self._port._filesystem.rmtree(str(self._driver_tempdir)) 337 self._driver_tempdir = None 338 339 self._current_cmd_line = None 340 341 def cmd_line(self, pixel_tests, per_test_args): 342 cmd = self._command_wrapper(self._port.get_option('wrapper')) 343 cmd.append(self._port._path_to_driver()) 344 if self._no_timeout: 345 cmd.append('--no-timeout') 346 cmd.extend(self._port.get_option('additional_drt_flag', [])) 347 cmd.extend(self._port.additional_drt_flag()) 348 if self._port.get_option('enable_leak_detection'): 349 cmd.append('--enable-leak-detection') 350 cmd.extend(per_test_args) 351 cmd.append('-') 352 return cmd 353 354 def _check_for_driver_crash(self, error_line): 355 if error_line == "#CRASHED\n": 356 # This is used on Windows to report that the process has crashed 357 # See http://trac.webkit.org/changeset/65537. 358 self._crashed_process_name = self._server_process.name() 359 self._crashed_pid = self._server_process.pid() 360 elif (error_line.startswith("#CRASHED - ") 361 or error_line.startswith("#PROCESS UNRESPONSIVE - ")): 362 # WebKitTestRunner uses this to report that the WebProcess subprocess crashed. 363 match = re.match('#(?:CRASHED|PROCESS UNRESPONSIVE) - (\S+)', error_line) 364 self._crashed_process_name = match.group(1) if match else 'WebProcess' 365 match = re.search('pid (\d+)', error_line) 366 pid = int(match.group(1)) if match else None 367 self._crashed_pid = pid 368 # FIXME: delete this after we're sure this code is working :) 369 _log.debug('%s crash, pid = %s, error_line = %s' % (self._crashed_process_name, str(pid), error_line)) 370 if error_line.startswith("#PROCESS UNRESPONSIVE - "): 371 self._subprocess_was_unresponsive = True 372 self._port.sample_process(self._crashed_process_name, self._crashed_pid) 373 # We want to show this since it's not a regular crash and probably we don't have a crash log. 374 self.error_from_test += error_line 375 return True 376 return self.has_crashed() 377 378 def _check_for_leak(self, error_line): 379 if error_line.startswith("#LEAK - "): 380 self._leaked = True 381 match = re.match('#LEAK - (\S+) pid (\d+) (.+)\n', error_line) 382 self._leak_log = match.group(3) 383 return self._leaked 384 385 def _command_from_driver_input(self, driver_input): 386 # FIXME: performance tests pass in full URLs instead of test names. 387 if driver_input.test_name.startswith('http://') or driver_input.test_name.startswith('https://') or driver_input.test_name == ('about:blank'): 388 command = driver_input.test_name 389 elif self.is_http_test(driver_input.test_name): 390 command = self.test_to_uri(driver_input.test_name) 391 else: 392 command = self._port.abspath_for_test(driver_input.test_name) 393 if sys.platform == 'cygwin': 394 command = path.cygpath(command) 395 396 assert not driver_input.image_hash or driver_input.should_run_pixel_test 397 398 # ' is the separator between arguments. 399 if self._port.supports_per_test_timeout(): 400 command += "'--timeout'%s" % driver_input.timeout 401 if driver_input.should_run_pixel_test: 402 command += "'--pixel-test" 403 if driver_input.image_hash: 404 command += "'" + driver_input.image_hash 405 return command + "\n" 406 407 def _read_first_block(self, deadline): 408 # returns (text_content, audio_content) 409 block = self._read_block(deadline) 410 if block.malloc: 411 self._measurements['Malloc'] = float(block.malloc) 412 if block.js_heap: 413 self._measurements['JSHeap'] = float(block.js_heap) 414 if block.content_type == 'audio/wav': 415 return (None, block.decoded_content) 416 return (block.decoded_content, None) 417 418 def _read_optional_image_block(self, deadline): 419 # returns (image, actual_image_hash) 420 block = self._read_block(deadline, wait_for_stderr_eof=True) 421 if block.content and block.content_type == 'image/png': 422 return (block.decoded_content, block.content_hash) 423 return (None, block.content_hash) 424 425 def _read_header(self, block, line, header_text, header_attr, header_filter=None): 426 if line.startswith(header_text) and getattr(block, header_attr) is None: 427 value = line.split()[1] 428 if header_filter: 429 value = header_filter(value) 430 setattr(block, header_attr, value) 431 return True 432 return False 433 434 def _process_stdout_line(self, block, line): 435 if (self._read_header(block, line, 'Content-Type: ', 'content_type') 436 or self._read_header(block, line, 'Content-Transfer-Encoding: ', 'encoding') 437 or self._read_header(block, line, 'Content-Length: ', '_content_length', int) 438 or self._read_header(block, line, 'ActualHash: ', 'content_hash') 439 or self._read_header(block, line, 'DumpMalloc: ', 'malloc') 440 or self._read_header(block, line, 'DumpJSHeap: ', 'js_heap') 441 or self._read_header(block, line, 'StdinPath', 'stdin_path')): 442 return 443 # Note, we're not reading ExpectedHash: here, but we could. 444 # If the line wasn't a header, we just append it to the content. 445 block.content += line 446 447 def _strip_eof(self, line): 448 if line and line.endswith("#EOF\n"): 449 return line[:-5], True 450 if line and line.endswith("#EOF\r\n"): 451 _log.error("Got a CRLF-terminated #EOF - this is a driver bug.") 452 return line[:-6], True 453 return line, False 454 455 def _read_block(self, deadline, wait_for_stderr_eof=False): 456 block = ContentBlock() 457 out_seen_eof = False 458 459 while not self.has_crashed(): 460 if out_seen_eof and (self.err_seen_eof or not wait_for_stderr_eof): 461 break 462 463 if self.err_seen_eof: 464 out_line = self._server_process.read_stdout_line(deadline) 465 err_line = None 466 elif out_seen_eof: 467 out_line = None 468 err_line = self._server_process.read_stderr_line(deadline) 469 else: 470 out_line, err_line = self._server_process.read_either_stdout_or_stderr_line(deadline) 471 472 if self._server_process.timed_out or self.has_crashed(): 473 break 474 475 if out_line: 476 assert not out_seen_eof 477 out_line, out_seen_eof = self._strip_eof(out_line) 478 if err_line: 479 assert not self.err_seen_eof 480 err_line, self.err_seen_eof = self._strip_eof(err_line) 481 482 if out_line: 483 if out_line[-1] != "\n": 484 _log.error("Last character read from DRT stdout line was not a newline! This indicates either a NRWT or DRT bug.") 485 content_length_before_header_check = block._content_length 486 self._process_stdout_line(block, out_line) 487 # FIXME: Unlike HTTP, DRT dumps the content right after printing a Content-Length header. 488 # Don't wait until we're done with headers, just read the binary blob right now. 489 if content_length_before_header_check != block._content_length: 490 if block._content_length > 0: 491 block.content = self._server_process.read_stdout(deadline, block._content_length) 492 else: 493 _log.error("Received content of type %s with Content-Length of 0! This indicates a bug in %s.", 494 block.content_type, self._server_process.name()) 495 496 if err_line: 497 if self._check_for_driver_crash(err_line): 498 break 499 if self._check_for_leak(err_line): 500 break 501 self.error_from_test += err_line 502 503 block.decode_content() 504 return block 505 506 507 class ContentBlock(object): 508 def __init__(self): 509 self.content_type = None 510 self.encoding = None 511 self.content_hash = None 512 self._content_length = None 513 # Content is treated as binary data even though the text output is usually UTF-8. 514 self.content = str() # FIXME: Should be bytearray() once we require Python 2.6. 515 self.decoded_content = None 516 self.malloc = None 517 self.js_heap = None 518 self.stdin_path = None 519 520 def decode_content(self): 521 if self.encoding == 'base64' and self.content is not None: 522 self.decoded_content = base64.b64decode(self.content) 523 else: 524 self.decoded_content = self.content 525