xcodebuild_runner.py

# Copyright 2018 The Chromium Authors. All rights reserved.
# Use of this source code is governed by a BSD-style license that can be
# found in the LICENSE file.

"""Test runner for running tests using xcodebuild."""

import collections
import distutils.version
import logging
from multiprocessing import pool
import os
import subprocess
import time

import file_util
import iossim_util
import standard_json_util as sju
import test_apps
import test_runner
import xcode_log_parser

LOGGER = logging.getLogger(__name__)
MAXIMUM_TESTS_PER_SHARD_FOR_RERUN = 20
XTDEVICE_FOLDER = os.path.expanduser('~/Library/Developer/XCTestDevices')


class LaunchCommandCreationError(test_runner.TestRunnerError):
  """One of launch command parameters was not set properly."""

  def __init__(self, message):
    super(LaunchCommandCreationError, self).__init__(message)


class LaunchCommandPoolCreationError(test_runner.TestRunnerError):
  """Failed to create a pool of launch commands."""

  def __init__(self, message):
    super(LaunchCommandPoolCreationError, self).__init__(message)


def erase_all_simulators(path=None):
  """Erases all simulator devices.

  Args:
    path: (str) A path with simulators
  """
  command = ['xcrun', 'simctl']
  if path:
    command += ['--set', path]
    LOGGER.info('Erasing all simulators from folder %s.' % path)
  else:
    LOGGER.info('Erasing all simulators.')

  try:
    subprocess.check_call(command + ['erase', 'all'])
  except subprocess.CalledProcessError as e:
    # Logging error instead of throwing so we don't cause failures in case
    # this was indeed failing to clean up.
    message = 'Failed to erase all simulators. Error: %s' % e.output
    LOGGER.error(message)


def shutdown_all_simulators(path=None):
  """Shutdown all simulator devices.

  Fix for DVTCoreSimulatorAdditionsErrorDomain error.

  Args:
    path: (str) A path with simulators
  """
  command = ['xcrun', 'simctl']
  if path:
    command += ['--set', path]
    LOGGER.info('Shutdown all simulators from folder %s.' % path)
  else:
    LOGGER.info('Shutdown all simulators.')

  try:
    subprocess.check_call(command + ['shutdown', 'all'])
  except subprocess.CalledProcessError as e:
    # Logging error instead of throwing so we don't cause failures in case
    # this was indeed failing to clean up.
    message = 'Failed to shutdown all simulators. Error: %s' % e.output
    LOGGER.error(message)


def terminate_process(proc):
  """Terminates the process.

  If an error occurs ignore it, just print out a message.

  Args:
    proc: A subprocess.
  """
  try:
    proc.terminate()
  except OSError as ex:
    LOGGER.error('Error while killing a process: %s' % ex)


class LaunchCommand(object):
  """Stores xcodebuild test launching command."""

  def __init__(self,
               egtests_app,
               udid,
               shards,
               retries,
               out_dir=os.path.basename(os.getcwd()),
               use_clang_coverage=False,
               env=None):
    """Initialize launch command.

    Args:
      egtests_app: (EgtestsApp) An egtests_app to run.
      udid: (str) UDID of a device/simulator.
      shards: (int) A number of shards.
      retries: (int) A number of retries.
      out_dir: (str) A folder in which xcodebuild will generate test output.
        By default it is a current directory.
      env: (dict) Environment variables.

    Raises:
      LaunchCommandCreationError: if one of parameters was not set properly.
    """
    if not isinstance(egtests_app, test_apps.EgtestsApp):
      raise test_runner.AppNotFoundError(
          'Parameter `egtests_app` is not EgtestsApp: %s' % egtests_app)
    self.egtests_app = egtests_app
    self.udid = udid
    self.shards = shards
    self.retries = retries
    self.out_dir = out_dir
    self.logs = collections.OrderedDict()
    self.test_results = collections.OrderedDict()
    self.use_clang_coverage = use_clang_coverage
    self.env = env
    self._log_parser = xcode_log_parser.get_parser()

  def summary_log(self):
    """Calculates test summary - how many passed, failed and error tests.

    Returns:
      Dictionary with number of passed and failed tests.
      Failed tests will be calculated from the last test attempt.
      Passed tests calculated for each test attempt.
    """
    test_statuses = ['passed', 'failed']
    for status in test_statuses:
      self.logs[status] = 0

    for index, test_attempt_results in enumerate(self.test_results['attempts']):
      for test_status in test_statuses:
        if test_status not in test_attempt_results:
          continue
        if (test_status == 'passed'
            # Number of failed tests is taken only from last run.
            or (test_status == 'failed'
                and index == len(self.test_results['attempts']) - 1)):
          self.logs[test_status] += len(test_attempt_results[test_status])

  def launch_attempt(self, cmd):
    """Launch a process and do logging simultaneously.

    Args:
      cmd: (list[str]) A command to run.

    Returns:
      output - command output as list of strings.
    """
    proc = subprocess.Popen(
        cmd,
        env=self.env,
        stdout=subprocess.PIPE,
        stderr=subprocess.STDOUT,
    )
    return test_runner.print_process_output(proc)

  def launch(self):
    """Launches tests using xcodebuild."""
    self.test_results['attempts'] = []
    cancelled_statuses = {'TESTS_DID_NOT_START', 'BUILD_INTERRUPTED'}
    shards = self.shards
    running_tests = set(self.egtests_app.get_all_tests())
    # total number of attempts is self.retries+1
    for attempt in range(self.retries + 1):
      # Erase all simulators per each attempt
      if iossim_util.is_device_with_udid_simulator(self.udid):
        # kill all running simulators to prevent possible memory leaks
        test_runner.SimulatorTestRunner.kill_simulators()
        shutdown_all_simulators()
        shutdown_all_simulators(XTDEVICE_FOLDER)
        erase_all_simulators()
        erase_all_simulators(XTDEVICE_FOLDER)
      outdir_attempt = os.path.join(self.out_dir, 'attempt_%d' % attempt)
      cmd_list = self.egtests_app.command(outdir_attempt, 'id=%s' % self.udid,
                                          shards)
      # TODO(crbug.com/914878): add heartbeat logging to xcodebuild_runner.
      LOGGER.info('Start test attempt #%d for command [%s]' % (
          attempt, ' '.join(cmd_list)))
      output = self.launch_attempt(cmd_list)

      if hasattr(self, 'use_clang_coverage') and self.use_clang_coverage:
        # out_dir of LaunchCommand object is the TestRunner out_dir joined with
        # UDID. Use os.path.dirname to retrieve the TestRunner out_dir.
        file_util.move_raw_coverage_data(self.udid,
                                         os.path.dirname(self.out_dir))
      self.test_results['attempts'].append(
          self._log_parser.collect_test_results(outdir_attempt, output))

      # Do not exit here when no failed test from parsed log and parallel
      # testing is enabled (shards > 1), because when one of the shards fails
      # before tests start , the tests not run don't appear in log at all.
      if (self.retries == attempt or
          (shards == 1 and not self.test_results['attempts'][-1]['failed'])):
        break

      # Exclude passed tests in next test attempt.
      self.egtests_app.excluded_tests += self.test_results['attempts'][-1][
          'passed']
      # crbug.com/987664 - for the case when
      # all tests passed but build was interrupted,
      # excluded(passed) tests are equal to tests to run.
      if set(self.egtests_app.excluded_tests) == running_tests:
        for status in cancelled_statuses:
          failure = self.test_results['attempts'][-1]['failed'].pop(
              status, None)
          if failure:
            LOGGER.info('Failure for passed tests %s: %s' % (status, failure))
        break

      # If tests are not completed(interrupted or did not start)
      # re-run them with the same number of shards,
      # otherwise re-run with shards=1 and exclude passed tests.
      cancelled_attempt = cancelled_statuses.intersection(
          self.test_results['attempts'][-1]['failed'].keys())

      # Item in cancelled_statuses is used to config for next attempt. The usage
      # should be confined in this method. Real tests affected by these statuses
      # will be marked timeout in results.
      for status in cancelled_statuses:
        self.test_results['attempts'][-1]['failed'].pop(status, None)

      if (not cancelled_attempt
          # If need to re-run less than 20 tests, 1 shard should be enough.
          or (len(running_tests) - len(self.egtests_app.excluded_tests)
              <= MAXIMUM_TESTS_PER_SHARD_FOR_RERUN)):
        shards = 1

    self.summary_log()

    return {
        'test_results': self.test_results,
        'logs': self.logs
    }


class SimulatorParallelTestRunner(test_runner.SimulatorTestRunner):
  """Class for running simulator tests using xCode."""

  def __init__(self,
               app_path,
               host_app_path,
               iossim_path,
               version,
               platform,
               out_dir,
               release=False,
               retries=1,
               shards=1,
               test_cases=None,
               test_args=None,
               use_clang_coverage=False,
               env_vars=None):
    """Initializes a new instance of SimulatorParallelTestRunner class.

    Args:
      app_path: (str) A path to egtests_app.
      host_app_path: (str) A path to the host app for EG2.
      iossim_path: Path to the compiled iossim binary to use.
                   Not used, but is required by the base class.
      version: (str) iOS version to run simulator on.
      platform: (str) Name of device.
      out_dir: (str) A directory to emit test data into.
      release: (bool) Whether this test runner is running for a release build.
      retries: (int) A number to retry test run, will re-run only failed tests.
      shards: (int) A number of shards. Default is 1.
      test_cases: (list) List of tests to be included in the test run.
                  None or [] to include all tests.
      test_args: List of strings to pass as arguments to the test when
        launching.
      use_clang_coverage: Whether code coverage is enabled in this run.
      env_vars: List of environment variables to pass to the test itself.

    Raises:
      AppNotFoundError: If the given app does not exist.
      PlugInsNotFoundError: If the PlugIns directory does not exist for XCTests.
      XcodeVersionNotFoundError: If the given Xcode version does not exist.
      XCTestPlugInNotFoundError: If the .xctest PlugIn does not exist.
    """
    super(SimulatorParallelTestRunner, self).__init__(
        app_path,
        iossim_path,
        platform,
        version,
        out_dir,
        env_vars=env_vars,
        retries=retries or 1,
        shards=shards or 1,
        test_args=test_args,
        test_cases=test_cases,
        use_clang_coverage=use_clang_coverage,
        xctest=False)
    self.set_up()
    self.host_app_path = None
    if host_app_path != 'NO_PATH':
      self.host_app_path = os.path.abspath(host_app_path)
    self._init_sharding_data()
    self.logs = collections.OrderedDict()
    self.release = release
    self.test_results['path_delimiter'] = '/'
    # Do not enable parallel testing when code coverage is enabled, because raw
    # coverage data won't be produced with parallel testing.
    if hasattr(self, 'use_clang_coverage') and self.use_clang_coverage:
      self.shards = 1

  def _init_sharding_data(self):
    """Initialize sharding data.

    For common case info about sharding tests will be a list of dictionaries:
    [
        {
            'app':paths to egtests_app,
            'udid': 'UDID of Simulator'
            'shards': N
        }
    ]
    """
    self.sharding_data = [{
        'app': self.app_path,
        'host': self.host_app_path,
        'udid': self.udid,
        'shards': self.shards,
        'test_cases': self.test_cases
    }]

  def get_launch_env(self):
    """Returns a dict of environment variables to use to launch the test app.

    Returns:
      A dict of environment variables.
    """
    env = super(test_runner.SimulatorTestRunner, self).get_launch_env()
    env['NSUnbufferedIO'] = 'YES'
    return env

  def get_launch_test_app(self, params):
    """Returns the proper test_app for the run, requiring sharding data.

    Args:
      params: A collection of sharding_data params.

    Returns:
      An implementation of EgtestsApp included the sharding_data params
    """
    return test_apps.EgtestsApp(
        params['app'],
        included_tests=params['test_cases'],
        env_vars=self.env_vars,
        test_args=self.test_args,
        release=self.release,
        host_app_path=params['host'])

  def launch(self):
    """Launches tests using xcodebuild."""
    launch_commands = []
    for params in self.sharding_data:
      test_app = self.get_launch_test_app(params)
      launch_commands.append(
          LaunchCommand(
              test_app,
              udid=params['udid'],
              shards=params['shards'],
              retries=self.retries,
              out_dir=os.path.join(self.out_dir, params['udid']),
              use_clang_coverage=(hasattr(self, 'use_clang_coverage') and
                                  self.use_clang_coverage),
              env=self.get_launch_env()))

    thread_pool = pool.ThreadPool(len(launch_commands))
    attempts_results = []
    for result in thread_pool.imap_unordered(LaunchCommand.launch,
                                             launch_commands):
      attempts_results.append(result['test_results']['attempts'])

    # Deletes simulator used in the tests after tests end.
    if iossim_util.is_device_with_udid_simulator(self.udid):
      iossim_util.delete_simulator_by_udid(self.udid)

    # Gets passed tests
    self.logs['passed tests'] = []
    for shard_attempts in attempts_results:
      for attempt in shard_attempts:
        self.logs['passed tests'].extend(attempt['passed'])

    # If the last attempt does not have failures, mark failed as empty
    self.logs['failed tests'] = []
    for shard_attempts in attempts_results:
      if shard_attempts[-1]['failed']:
        self.logs['failed tests'].extend(shard_attempts[-1]['failed'].keys())

    # Gets disabled tests from test app object if any.
    self.logs['disabled tests'] = []
    for launch_command in launch_commands:
      self.logs['disabled tests'].extend(
          launch_command.egtests_app.disabled_tests)

    # Gets all failures/flakes and lists them in bot summary
    all_failures = set()
    for shard_attempts in attempts_results:
      for attempt, attempt_results in enumerate(shard_attempts):
        for failure in attempt_results['failed']:
          if failure not in self.logs:
            self.logs[failure] = []
          self.logs[failure].append('%s: attempt # %d' % (failure, attempt))
          self.logs[failure].extend(attempt_results['failed'][failure])
          all_failures.add(failure)

    # Gets only flaky(not failed) tests.
    self.logs['flaked tests'] = list(
        all_failures - set(self.logs['failed tests']))

    # Gets not-started/interrupted tests.
    # all_tests_to_run takes into consideration that only a subset of tests may
    # have run due to the test sharding logic in run.py.
    all_tests_to_run = set([
        test_name for launch_command in launch_commands
        for test_name in launch_command.egtests_app.get_all_tests()
    ])

    aborted_tests = []
    # TODO(crbug.com/1048758): For device targets, the list of test names parsed
    # from otool output is incorrect. For multitasking or any flaky test suite,
    # the list contains more tests than what actually runs.
    if (self.__class__.__name__ != 'DeviceXcodeTestRunner' and
        'ios_chrome_multitasking_eg' not in self.app_path and
        '_flaky_eg' not in self.app_path):
      aborted_tests = list(all_tests_to_run - set(self.logs['failed tests']) -
                           set(self.logs['passed tests']))
    aborted_tests.sort()
    self.logs['aborted tests'] = aborted_tests

    self.test_results['interrupted'] = bool(aborted_tests)
    self.test_results['num_failures_by_type'] = {
        'FAIL': len(self.logs['failed tests'] + self.logs['aborted tests']),
        'PASS': len(self.logs['passed tests']),
    }

    output = sju.StdJson()
    for shard_attempts in attempts_results:
      for attempt, attempt_results in enumerate(shard_attempts):

        for test in attempt_results['failed'].keys():
          output.mark_failed(
              test, test_log='\n'.join(self.logs.get(test, [])).encode('utf8'))

        # 'aborted tests' in logs is an array of strings, each string defined
        # as "{TestCase}/{testMethod}"
        for test in self.logs['aborted tests']:
          output.mark_timeout(test)

        for test in attempt_results['passed']:
          output.mark_passed(test)

    output.mark_all_skipped(self.logs['disabled tests'])
    output.finalize()

    self.test_results['tests'] = output.tests

    # Test is failed if there are failures for the last run.
    # or if there are aborted tests.
    return not self.logs['failed tests'] and not self.logs['aborted tests']


class DeviceXcodeTestRunner(SimulatorParallelTestRunner,
                            test_runner.DeviceTestRunner):
  """Class for running tests on real device using xCode."""

  def __init__(
      self,
      app_path,
      host_app_path,
      out_dir,
      release=False,
      retries=1,
      test_cases=None,
      test_args=None,
      env_vars=None,
  ):
    """Initializes a new instance of DeviceXcodeTestRunner class.

    Args:
      app_path: (str) A path to egtests_app.
      host_app_path: (str) A path to the host app for EG2.
      out_dir: (str) A directory to emit test data into.
      retries: (int) A number to retry test run, will re-run only failed tests.
      test_cases: (list) List of tests to be included in the test run.
                  None or [] to include all tests.
      test_args: List of strings to pass as arguments to the test when
        launching.
      env_vars: List of environment variables to pass to the test itself.

    Raises:
      AppNotFoundError: If the given app does not exist.
      DeviceDetectionError: If no device found.
      PlugInsNotFoundError: If the PlugIns directory does not exist for XCTests.
      XcodeVersionNotFoundError: If the given Xcode version does not exist.
      XCTestPlugInNotFoundError: If the .xctest PlugIn does not exist.
    """
    test_runner.DeviceTestRunner.__init__(
        self,
        app_path,
        out_dir,
        env_vars=env_vars,
        retries=retries,
        test_args=test_args,
        test_cases=test_cases,
    )
    self.shards = 1  # For tests on real devices shards=1
    self.version = None
    self.platform = None
    self.host_app_path = None
    if host_app_path != 'NO_PATH':
      self.host_app_path = os.path.abspath(host_app_path)
    self.homedir = ''
    self.release = release
    self.set_up()
    self._init_sharding_data()
    self.start_time = time.strftime('%Y-%m-%d-%H%M%S', time.localtime())
    self.test_results['path_delimiter'] = '/'

  def set_up(self):
    """Performs setup actions which must occur prior to every test launch."""
    self.uninstall_apps()
    self.wipe_derived_data()

  def tear_down(self):
    """Performs cleanup actions which must occur after every test launch."""
    test_runner.DeviceTestRunner.tear_down(self)

  def launch(self):
    try:
      return super(DeviceXcodeTestRunner, self).launch()
    finally:
      self.tear_down()