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 self.start(driver_input.should_run_pixel_test, driver_input.args) 154 test_begin_time = time.time() 155 self.error_from_test = str() 156 self.err_seen_eof = False 157 158 command = self._command_from_driver_input(driver_input) 159 deadline = test_begin_time + int(driver_input.timeout) / 1000.0 160 161 self._server_process.write(command) 162 text, audio = self._read_first_block(deadline) # First block is either text or audio 163 image, actual_image_hash = self._read_optional_image_block(deadline) # The second (optional) block is image data. 164 165 crashed = self.has_crashed() 166 timed_out = self._server_process.timed_out 167 pid = self._server_process.pid() 168 leaked = self._leaked 169 170 if not crashed and 'AddressSanitizer' in self.error_from_test: 171 self.error_from_test = 'OUTPUT CONTAINS "AddressSanitizer", so we are treating this test as if it crashed, even though it did not.\n\n' + self.error_from_test 172 crashed = True 173 self._crashed_process_name = "unknown process name" 174 self._crashed_pid = 0 175 176 if stop_when_done or crashed or timed_out or leaked: 177 # We call stop() even if we crashed or timed out in order to get any remaining stdout/stderr output. 178 # In the timeout case, we kill the hung process as well. 179 out, err = self._server_process.stop(self._port.driver_stop_timeout() if stop_when_done else 0.0) 180 if out: 181 text += out 182 if err: 183 self.error_from_test += err 184 self._server_process = None 185 186 crash_log = None 187 if crashed: 188 self.error_from_test, crash_log = self._get_crash_log(text, self.error_from_test, newer_than=start_time) 189 190 # If we don't find a crash log use a placeholder error message instead. 191 if not crash_log: 192 pid_str = str(self._crashed_pid) if self._crashed_pid else "unknown pid" 193 crash_log = 'No crash log found for %s:%s.\n' % (self._crashed_process_name, pid_str) 194 # If we were unresponsive append a message informing there may not have been a crash. 195 if self._subprocess_was_unresponsive: 196 crash_log += 'Process failed to become responsive before timing out.\n' 197 198 # Print stdout and stderr to the placeholder crash log; we want as much context as possible. 199 if self.error_from_test: 200 crash_log += '\nstdout:\n%s\nstderr:\n%s\n' % (text, self.error_from_test) 201 202 return DriverOutput(text, image, actual_image_hash, audio, 203 crash=crashed, test_time=time.time() - test_begin_time, measurements=self._measurements, 204 timeout=timed_out, error=self.error_from_test, 205 crashed_process_name=self._crashed_process_name, 206 crashed_pid=self._crashed_pid, crash_log=crash_log, 207 leak=leaked, leak_log=self._leak_log, 208 pid=pid) 209 210 def _get_crash_log(self, stdout, stderr, newer_than): 211 return self._port._get_crash_log(self._crashed_process_name, self._crashed_pid, stdout, stderr, newer_than) 212 213 # FIXME: Seems this could just be inlined into callers. 214 @classmethod 215 def _command_wrapper(cls, wrapper_option): 216 # Hook for injecting valgrind or other runtime instrumentation, 217 # used by e.g. tools/valgrind/valgrind_tests.py. 218 return shlex.split(wrapper_option) if wrapper_option else [] 219 220 HTTP_DIR = "http/tests/" 221 HTTP_LOCAL_DIR = "http/tests/local/" 222 223 def is_http_test(self, test_name): 224 return test_name.startswith(self.HTTP_DIR) and not test_name.startswith(self.HTTP_LOCAL_DIR) 225 226 def test_to_uri(self, test_name): 227 """Convert a test name to a URI.""" 228 if not self.is_http_test(test_name): 229 return path.abspath_to_uri(self._port.host.platform, self._port.abspath_for_test(test_name)) 230 231 relative_path = test_name[len(self.HTTP_DIR):] 232 233 # TODO(dpranke): remove the SSL reference? 234 if relative_path.startswith("ssl/"): 235 return "https://127.0.0.1:8443/" + relative_path 236 return "http://127.0.0.1:8000/" + relative_path 237 238 def uri_to_test(self, uri): 239 """Return the base layout test name for a given URI. 240 241 This returns the test name for a given URI, e.g., if you passed in 242 "file:///src/LayoutTests/fast/html/keygen.html" it would return 243 "fast/html/keygen.html". 244 245 """ 246 if uri.startswith("file:///"): 247 prefix = path.abspath_to_uri(self._port.host.platform, self._port.layout_tests_dir()) 248 if not prefix.endswith('/'): 249 prefix += '/' 250 return uri[len(prefix):] 251 if uri.startswith("http://"): 252 return uri.replace('http://127.0.0.1:8000/', self.HTTP_DIR) 253 if uri.startswith("https://"): 254 return uri.replace('https://127.0.0.1:8443/', self.HTTP_DIR) 255 raise NotImplementedError('unknown url type: %s' % uri) 256 257 def has_crashed(self): 258 if self._server_process is None: 259 return False 260 if self._crashed_process_name: 261 return True 262 if self._server_process.has_crashed(): 263 self._crashed_process_name = self._server_process.name() 264 self._crashed_pid = self._server_process.pid() 265 return True 266 return False 267 268 def start(self, pixel_tests, per_test_args): 269 new_cmd_line = self.cmd_line(pixel_tests, per_test_args) 270 if not self._server_process or new_cmd_line != self._current_cmd_line: 271 self._start(pixel_tests, per_test_args) 272 self._run_post_start_tasks() 273 274 def _setup_environ_for_driver(self, environment): 275 if self._profiler: 276 environment = self._profiler.adjusted_environment(environment) 277 return environment 278 279 def _start(self, pixel_tests, per_test_args, wait_for_ready=True): 280 self.stop() 281 self._driver_tempdir = self._port._filesystem.mkdtemp(prefix='%s-' % self._port.driver_name()) 282 server_name = self._port.driver_name() 283 environment = self._port.setup_environ_for_server(server_name) 284 environment = self._setup_environ_for_driver(environment) 285 self._crashed_process_name = None 286 self._crashed_pid = None 287 self._leaked = False 288 self._leak_log = None 289 cmd_line = self.cmd_line(pixel_tests, per_test_args) 290 self._server_process = self._port._server_process_constructor(self._port, server_name, cmd_line, environment, logging=self._port.get_option("driver_logging")) 291 self._server_process.start() 292 self._current_cmd_line = cmd_line 293 294 if wait_for_ready: 295 deadline = time.time() + DRIVER_START_TIMEOUT_SECS 296 if not self._wait_for_server_process_output(self._server_process, deadline, '#READY'): 297 _log.error("content_shell took too long to startup.") 298 299 def _wait_for_server_process_output(self, server_process, deadline, text): 300 output = '' 301 line = server_process.read_stdout_line(deadline) 302 while not server_process.timed_out and not server_process.has_crashed() and not text in line.rstrip(): 303 output += line 304 line = server_process.read_stdout_line(deadline) 305 306 if server_process.timed_out or server_process.has_crashed(): 307 _log.error('Failed to start the %s process: \n%s' % (server_process.name(), output)) 308 return False 309 310 return True 311 312 def _run_post_start_tasks(self): 313 # Remote drivers may override this to delay post-start tasks until the server has ack'd. 314 if self._profiler: 315 self._profiler.attach_to_pid(self._pid_on_target()) 316 317 def _pid_on_target(self): 318 # Remote drivers will override this method to return the pid on the device. 319 return self._server_process.pid() 320 321 def stop(self): 322 if self._server_process: 323 self._server_process.stop() 324 self._server_process = None 325 if self._profiler: 326 self._profiler.profile_after_exit() 327 328 if self._driver_tempdir: 329 self._port._filesystem.rmtree(str(self._driver_tempdir)) 330 self._driver_tempdir = None 331 332 self._current_cmd_line = None 333 334 def cmd_line(self, pixel_tests, per_test_args): 335 cmd = self._command_wrapper(self._port.get_option('wrapper')) 336 cmd.append(self._port._path_to_driver()) 337 if self._no_timeout: 338 cmd.append('--no-timeout') 339 cmd.extend(self._port.get_option('additional_drt_flag', [])) 340 cmd.extend(self._port.additional_drt_flag()) 341 if self._port.get_option('enable_leak_detection'): 342 cmd.append('--enable-leak-detection') 343 cmd.extend(per_test_args) 344 cmd.append('-') 345 return cmd 346 347 def _check_for_driver_crash(self, error_line): 348 if error_line == "#CRASHED\n": 349 # This is used on Windows to report that the process has crashed 350 # See http://trac.webkit.org/changeset/65537. 351 self._crashed_process_name = self._server_process.name() 352 self._crashed_pid = self._server_process.pid() 353 elif (error_line.startswith("#CRASHED - ") 354 or error_line.startswith("#PROCESS UNRESPONSIVE - ")): 355 # WebKitTestRunner uses this to report that the WebProcess subprocess crashed. 356 match = re.match('#(?:CRASHED|PROCESS UNRESPONSIVE) - (\S+)', error_line) 357 self._crashed_process_name = match.group(1) if match else 'WebProcess' 358 match = re.search('pid (\d+)', error_line) 359 pid = int(match.group(1)) if match else None 360 self._crashed_pid = pid 361 # FIXME: delete this after we're sure this code is working :) 362 _log.debug('%s crash, pid = %s, error_line = %s' % (self._crashed_process_name, str(pid), error_line)) 363 if error_line.startswith("#PROCESS UNRESPONSIVE - "): 364 self._subprocess_was_unresponsive = True 365 self._port.sample_process(self._crashed_process_name, self._crashed_pid) 366 # We want to show this since it's not a regular crash and probably we don't have a crash log. 367 self.error_from_test += error_line 368 return True 369 return self.has_crashed() 370 371 def _check_for_leak(self, error_line): 372 if error_line.startswith("#LEAK - "): 373 self._leaked = True 374 match = re.match('#LEAK - (\S+) pid (\d+) (.+)\n', error_line) 375 self._leak_log = match.group(3) 376 return self._leaked 377 378 def _command_from_driver_input(self, driver_input): 379 # FIXME: performance tests pass in full URLs instead of test names. 380 if driver_input.test_name.startswith('http://') or driver_input.test_name.startswith('https://') or driver_input.test_name == ('about:blank'): 381 command = driver_input.test_name 382 elif self.is_http_test(driver_input.test_name): 383 command = self.test_to_uri(driver_input.test_name) 384 else: 385 command = self._port.abspath_for_test(driver_input.test_name) 386 if sys.platform == 'cygwin': 387 command = path.cygpath(command) 388 389 assert not driver_input.image_hash or driver_input.should_run_pixel_test 390 391 # ' is the separator between arguments. 392 if self._port.supports_per_test_timeout(): 393 command += "'--timeout'%s" % driver_input.timeout 394 if driver_input.should_run_pixel_test: 395 command += "'--pixel-test" 396 if driver_input.image_hash: 397 command += "'" + driver_input.image_hash 398 return command + "\n" 399 400 def _read_first_block(self, deadline): 401 # returns (text_content, audio_content) 402 block = self._read_block(deadline) 403 if block.malloc: 404 self._measurements['Malloc'] = float(block.malloc) 405 if block.js_heap: 406 self._measurements['JSHeap'] = float(block.js_heap) 407 if block.content_type == 'audio/wav': 408 return (None, block.decoded_content) 409 return (block.decoded_content, None) 410 411 def _read_optional_image_block(self, deadline): 412 # returns (image, actual_image_hash) 413 block = self._read_block(deadline, wait_for_stderr_eof=True) 414 if block.content and block.content_type == 'image/png': 415 return (block.decoded_content, block.content_hash) 416 return (None, block.content_hash) 417 418 def _read_header(self, block, line, header_text, header_attr, header_filter=None): 419 if line.startswith(header_text) and getattr(block, header_attr) is None: 420 value = line.split()[1] 421 if header_filter: 422 value = header_filter(value) 423 setattr(block, header_attr, value) 424 return True 425 return False 426 427 def _process_stdout_line(self, block, line): 428 if (self._read_header(block, line, 'Content-Type: ', 'content_type') 429 or self._read_header(block, line, 'Content-Transfer-Encoding: ', 'encoding') 430 or self._read_header(block, line, 'Content-Length: ', '_content_length', int) 431 or self._read_header(block, line, 'ActualHash: ', 'content_hash') 432 or self._read_header(block, line, 'DumpMalloc: ', 'malloc') 433 or self._read_header(block, line, 'DumpJSHeap: ', 'js_heap')): 434 return 435 # Note, we're not reading ExpectedHash: here, but we could. 436 # If the line wasn't a header, we just append it to the content. 437 block.content += line 438 439 def _strip_eof(self, line): 440 if line and line.endswith("#EOF\n"): 441 return line[:-5], True 442 if line and line.endswith("#EOF\r\n"): 443 _log.error("Got a CRLF-terminated #EOF - this is a driver bug.") 444 return line[:-6], True 445 return line, False 446 447 def _read_block(self, deadline, wait_for_stderr_eof=False): 448 block = ContentBlock() 449 out_seen_eof = False 450 451 while not self.has_crashed(): 452 if out_seen_eof and (self.err_seen_eof or not wait_for_stderr_eof): 453 break 454 455 if self.err_seen_eof: 456 out_line = self._server_process.read_stdout_line(deadline) 457 err_line = None 458 elif out_seen_eof: 459 out_line = None 460 err_line = self._server_process.read_stderr_line(deadline) 461 else: 462 out_line, err_line = self._server_process.read_either_stdout_or_stderr_line(deadline) 463 464 if self._server_process.timed_out or self.has_crashed(): 465 break 466 467 if out_line: 468 assert not out_seen_eof 469 out_line, out_seen_eof = self._strip_eof(out_line) 470 if err_line: 471 assert not self.err_seen_eof 472 err_line, self.err_seen_eof = self._strip_eof(err_line) 473 474 if out_line: 475 if out_line[-1] != "\n": 476 _log.error("Last character read from DRT stdout line was not a newline! This indicates either a NRWT or DRT bug.") 477 content_length_before_header_check = block._content_length 478 self._process_stdout_line(block, out_line) 479 # FIXME: Unlike HTTP, DRT dumps the content right after printing a Content-Length header. 480 # Don't wait until we're done with headers, just read the binary blob right now. 481 if content_length_before_header_check != block._content_length: 482 if block._content_length > 0: 483 block.content = self._server_process.read_stdout(deadline, block._content_length) 484 else: 485 _log.error("Received content of type %s with Content-Length of 0! This indicates a bug in %s.", 486 block.content_type, self._server_process.name()) 487 488 if err_line: 489 if self._check_for_driver_crash(err_line): 490 break 491 if self._check_for_leak(err_line): 492 break 493 self.error_from_test += err_line 494 495 block.decode_content() 496 return block 497 498 499 class ContentBlock(object): 500 def __init__(self): 501 self.content_type = None 502 self.encoding = None 503 self.content_hash = None 504 self._content_length = None 505 # Content is treated as binary data even though the text output is usually UTF-8. 506 self.content = str() # FIXME: Should be bytearray() once we require Python 2.6. 507 self.decoded_content = None 508 self.malloc = None 509 self.js_heap = None 510 511 def decode_content(self): 512 if self.encoding == 'base64' and self.content is not None: 513 self.decoded_content = base64.b64decode(self.content) 514 else: 515 self.decoded_content = self.content 516
