src/third_party/WebKit/Tools/Scripts/webkitpy/layout_tests/port/driver.py

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