[Android] Implement perf tests to platform mode.

build/android/pylib/local/device/local_device_perf_test_run.py

+# Copyright 2016 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.
+
+import io
+import json
+import logging
+import os
+import pickle
+import shutil
+import tempfile
+import time
+import zipfile
+
+from devil.android import battery_utils
+from devil.android import device_errors
+from devil.android import device_list
+from devil.android import device_utils
+from devil.android import forwarder
+from devil.android.tools import device_recovery
+from devil.utils import cmd_helper
+from devil.utils import reraiser_thread
+from devil.utils import watchdog_timer
+from pylib import constants
+from pylib.base import base_test_result
+from pylib.constants import host_paths
+from pylib.local.device import local_device_test_run
+
+
+class TestShard(object):
+  def __init__(self, env, test_instance, device, index, tests, results,
+               watcher=None, retries=3, timeout=None):
+    logging.info('Create shard %s for device %s to run the following tests:',
+                 index, device)
+    for t in tests:
+      logging.info('  %s', t)
+    self._battery = battery_utils.BatteryUtils(device)
+    self._device = device
+    self._env = env
+    self._index = index
+    self._output_dir = None
+    self._results = results
+    self._retries = retries
+    self._test_instance = test_instance
+    self._tests = tests
+    self._timeout = timeout
+    self._watcher = watcher
+
+  def _TestSetUp(self, test):
+    if self._watcher:
+      self._watcher.Reset()
+
+    logging.info('Charge level: %s%%',
+                 str(self._battery.GetBatteryInfo().get('level')))
+    if self._test_instance.min_battery_level:
+      self._battery.ChargeDeviceToLevel(self._test_instance.min_battery_level)
+
+    logging.info('temperature: %s (0.1 C)',
+                 str(self._battery.GetBatteryInfo().get('temperature')))
+    if self._test_instance.max_battery_temp:
+      self._battery.LetBatteryCoolToTemperature(
+          self._test_instance.max_battery_temp)
+
+    if not self._device.IsScreenOn():
+      self._device.SetScreen(True)
+
+    if not self._device.IsOnline():
+      msg = 'Device %s is unresponsive.' % str(self._device)
+      raise device_errors.DeviceUnreachableError(msg)
+    if self._output_dir:
+      shutil.rmtree(self._output_dir)
+    if (self._test_instance.collect_chartjson_data
+        or self._tests[test].get('archive_output_dir')):
+      self._output_dir = tempfile.mkdtemp()
+    if self._watcher:
+      self._watcher.Reset()
+
+  def _TestTearDown(self):
+    try:
+      logging.info('Unmapping device ports for %s.', self._device)
+      forwarder.Forwarder.UnmapAllDevicePorts(self._device)

[jbudorick, 2016/06/28 10:27:32]

Why is this unmapping but not mapping? What's misbehaving and not unmapping
ports? Can we only do this if there are ports forwarded?

[rnephew (Reviews Here), 2016/06/29 22:27:19]

run_benchmark takes care of the mapping. This just makes sure nothing is mapped
after it attempts to do that in case it exited badly in the last run.

[jbudorick, 2016/07/01 14:20:09]

Does the instance of the Forwarder in this process even know about the ports
mapped by the instance of Forwarder in run_benchmark's process?

[jbudorick, 2016/07/06 19:12:09]

^

+    except Exception: # pylint: disable=broad-except
+      logging.exception('Exception when resetting ports.')
+
+  def _CreateCmd(self, test):
+    cmd = '%s --device %s' % (self._tests[test]['cmd'], str(self._device))
+    if self._output_dir:
+      cmd = cmd + ' --output-dir=%s' % self._output_dir
+    if self._test_instance.dry_run:
+      cmd = 'echo %s' % cmd
+    return cmd
+
+  def _RunSingleTest(self, test):
+
+    logging.info('Running %s on shard %s', test, self._index)

[jbudorick, 2016/06/28 10:27:33]

str(self._index) or %d?

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+    timeout = (
+        None if self._test_instance.no_timeout
+        else self._tests[test].get('timeout', self._timeout))
+    logging.info('Timeout for %s test: %s', test, timeout)

[jbudorick, 2016/06/28 10:27:32]

str(timeout) or %d?

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+
+    cmd = self._CreateCmd(test)
+    self._test_instance.WriteBuildBotJson(self._output_dir)
+    cwd = os.path.abspath(host_paths.DIR_SOURCE_ROOT)
+
+    try:
+      logging.debug('Running test with command \'%s\'', cmd)

[jbudorick, 2016/06/28 10:27:32]

nit: Use double quotes for the string when it contains single quotes s.t. you
don't have to escape

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+      start_time = time.time()
+      exit_code, output = cmd_helper.GetCmdStatusAndOutputWithTimeout(
+          cmd, timeout, cwd=cwd, shell=True)
+      end_time = time.time()
+      json_output = self._test_instance.ReadChartjsonOutput(self._output_dir)
+    except cmd_helper.TimeoutError as e:
+      exit_code = -1
+      output = e.output
+      json_output = ''
+
+    return self._ProcessTestResult(
+        test, cmd, start_time, end_time, exit_code, output, json_output)
+
+  def _ProcessTestResult(
+      self, test, cmd, start_time, end_time, exit_code, output, json_output):
+    if exit_code is None:
+      exit_code = -1
+    logging.info('%s : exit_code=%d in %d secs on device %s',
+                 test, exit_code, end_time - start_time,
+                 str(self._device))
+    if exit_code == 0:
+      result_type = base_test_result.ResultType.PASS
+    else:
+      result_type = base_test_result.ResultType.FAIL
+      # TODO(rnephew): Improve device recovery logic.

[jbudorick, 2016/06/28 10:27:32]

Why is this in _ProcessTestResult? I think this should be in RunTestsOnShard (or
in its own function called by RunTestsOnShard)

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+      try:
+        device_recovery.RecoverDevice(self._device, self._env.blacklist)
+      except device_errors.CommandTimeoutError:
+        logging.exception('Device failed to return after %s.', test)
+    actual_exit_code = exit_code
+    if (self._test_instance.flaky_steps
+        and test in self._test_instance.flaky_steps):
+      exit_code = 0
+    archive_bytes = (self._ArchiveOutputDir()
+                     if self._tests[test].get('archive_output_dir')
+                     else None)
+    persisted_result = {
+        'name': test,
+        'output': [output],
+        'chartjson': json_output,
+        'archive_bytes': archive_bytes,
+        'exit_code': exit_code,
+        'actual_exit_code': actual_exit_code,
+        'result_type': result_type,
+        'start_time': start_time,
+        'end_time': end_time,
+        'total_time': end_time - start_time,
+        'device': str(self._device),
+        'cmd': cmd,
+    }
+    self._SaveResult(persisted_result)
+    return result_type
+
+  @local_device_test_run.handle_shard_failures
+  def RunTestsOnShard(self):

[jbudorick, 2016/06/28 10:27:32]

The functions in this class are ordered strangely. Try to arrange them s.t. they
appear roughly in the order they're called, e.g.

  RunTestsOnShard
  _TestSetUp
  _RunSingleTest
  _CreateCmd
  _ProcessTestResult
  _ArchiveOutputDir
  _SaveResult
  _TestTearDown

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+    for test in self._tests:
+      try:
+        tries_left = self._retries
+        result_type = None
+        while (result_type != base_test_result.ResultType.PASS

[jbudorick, 2016/06/28 10:27:32]

This retry mechanism is the inverse of how gtests & instrumentation tests handle
retries. Is that how the old perf test runner handles them? What's the reasoning
if so?

[rnephew (Reviews Here), 2016/06/29 22:27:19]

So that we do not have to store which tests are passed/failed. We just run
through the list and when we reach the end we are done.

[jbudorick, 2016/07/01 14:20:09]

sgtm

+               and tries_left > 0):
+          try:
+            self._TestSetUp(test)
+            result_type = self._RunSingleTest(test)
+          except Exception: # pylint: disable=broad-except
+            logging.exception('Exception when executing %s.', test)
+            result_type = base_test_result.ResultType.FAIL
+          finally:
+            tries_left = tries_left - 1
+            self._TestTearDown()
+        result = base_test_result.TestRunResults()
+        result.AddResult(base_test_result.BaseTestResult(test, result_type))
+        self._results.append(result)
+      finally:
+        if self._output_dir:
+          shutil.rmtree(self._output_dir, ignore_errors=True)
+          self._output_dir = None
+
+  @staticmethod
+  def _SaveResult(result):
+    pickled = os.path.join(constants.PERF_OUTPUT_DIR, result['name'])
+    if os.path.exists(pickled):
+      with file(pickled, 'r') as f:
+        previous = pickle.loads(f.read())
+        result['output'] = previous['output'] + result['output']
+    with file(pickled, 'w') as f:
+      f.write(pickle.dumps(result))
+
+  def _ArchiveOutputDir(self):
+    """Archive all files in the output dir, and return as compressed bytes."""
+    with io.BytesIO() as archive:
+      with zipfile.ZipFile(archive, 'w', zipfile.ZIP_DEFLATED) as contents:
+        num_files = 0
+        for absdir, _, files in os.walk(self._output_dir):
+          reldir = os.path.relpath(absdir, self._output_dir)
+          for filename in files:
+            src_path = os.path.join(absdir, filename)
+            # We use normpath to turn './file.txt' into just 'file.txt'.
+            dst_path = os.path.normpath(os.path.join(reldir, filename))
+            contents.write(src_path, dst_path)
+            num_files += 1
+      if num_files:
+        logging.info('%d files in the output dir were archived.', num_files)
+      else:
+        logging.warning('No files in the output dir. Archive is empty.')
+      return archive.getvalue()
+
+
+class LocalDevicePerfTestRun(local_device_test_run.LocalDeviceTestRun):
+  def __init__(self, env, test_instance):
+    super(LocalDevicePerfTestRun, self).__init__(env, test_instance)
+    self._test_instance = test_instance
+    self._env = env
+    self._timeout = None if test_instance.no_timeout else 60 * 60
+    self._devices = None
+    self._test_buckets = []
+    self._watcher = None
+
+  def SetUp(self):
+    self._devices = self._GetAllDevices(self._env.devices,
+                                        self._test_instance.known_devices_file)
+    self._watcher = watchdog_timer.WatchdogTimer(self._timeout)
+
+    if (not (self._test_instance.print_step
+             or self._test_instance.output_json_list)):
+      if os.path.exists(constants.PERF_OUTPUT_DIR):
+        shutil.rmtree(constants.PERF_OUTPUT_DIR)
+      os.makedirs(constants.PERF_OUTPUT_DIR)
+
+  def TearDown(self):
+    pass
+
+  def _GetStepsFromDict(self):
+    # From where this is called one of these two must be set.
+    if self._test_instance.single_step:
+      return {
+          'version': 1,
+          'steps': {
+              'single_step': {
+                'device_affinity': 0,
+                'cmd': self._test_instance.single_step
+              },
+          }
+      }
+    if self._test_instance.steps:
+      with file(self._test_instance.steps, 'r') as f:
+        steps = json.load(f)
+        if steps['version'] != 1:
+          raise VersionError(
+              'Version is expected to be %d but was %d' % (1, steps['version']))
+        return steps
+
+  def _SplitTestsByAffinity(self):
+    test_dict = self._GetStepsFromDict()
+    for test, test_config in test_dict['steps'].iteritems():
+      try:
+        affinity = test_config['device_affinity']
+        if len(self._test_buckets) < affinity + 1:
+          while len(self._test_buckets) != affinity + 1:
+            self._test_buckets.append({})
+        self._test_buckets[affinity][test] = test_config
+      except KeyError:
+        logging.exception('Bad test config')
+    return self._test_buckets
+
+  @staticmethod
+  def _GetAllDevices(active_devices, devices_path):
+    try:
+      if devices_path:
+        devices = [device_utils.DeviceUtils(s)

[jbudorick, 2016/06/28 10:27:32]

port over https://codereview.chromium.org/2070043002

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+                   for s in device_list.GetPersistentDeviceList(devices_path)]
+      else:
+        logging.warning('Known devices file path not being passed. For device '
+                        'affinity to work properly, it must be passed.')
+        devices = active_devices
+    except IOError as e:
+      logging.error('Unable to find %s [%s]', devices_path, e)
+      devices = active_devices
+    return sorted(devices)
+
+  def RunTests(self):
+    # Option selected for saving a json file with a list of test names.
+    if self._test_instance.output_json_list:

[jbudorick, 2016/06/28 10:27:32]

I'm wondering if these should be subcommands of 'perf' -- something like

  test_runner.py perf output ...
  test_runner.py perf print ...
  test_runner.py perf run ...

You could conceivably have separate test_run classes for each in that case,
which may be a bit cleaner if a bit more verbose.

[rnephew (Reviews Here), 2016/06/29 22:27:19]

It could be switched to that if you want; but probably a lot of boilerplate for
little benefit. 

[rnephew (Reviews Here), 2016/06/30 19:10:36]

Moved them to their own classes in the same file.

+      return self._test_instance.RunOutputJsonList()
+
+    # Just print the results from a single previously executed step.
+    if self._test_instance.print_step:
+      return self._test_instance.RunPrintStep()
+
+    # Affinitize the tests.
+    test_buckets = self._SplitTestsByAffinity()
+    if not test_buckets:
+      raise local_device_test_run.NoTestsError()
+    threads = []
+    results = []
+    for x in xrange(min(len(self._devices), len(test_buckets))):

[jbudorick, 2016/06/28 10:27:32]

I think you could do this as:

  def run_perf_tests(x):
    s = TestShard(self._env, self._test_instance, self._devices[x], x,
test_buckets[x], ...)
    s.RunTestsOnShard()

  device_indices = range(min(len(self.devices), len(test_buckets)))
  shards = parallelizer.Parallelizer(device_indices).pMap(run_perf_tests)
  return shards.pGet(self._timeout)

WDYT? I think the log messages would look like

  TimeoutThread-1-for-run_perf_tests(1)

and I think it'd clean up a lot of the thread logic you're doing manually in
here.

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+      new_shard = TestShard(self._env, self._test_instance, self._devices[x], x,

[jbudorick, 2016/06/28 10:27:32]

I don't think we should make a shard for a device if it's blacklisted coming in.
(i.e., port https://codereview.chromium.org/2084493003)

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+                            test_buckets[x], results, watcher=self._watcher,
+                            retries=self._env.max_tries, timeout=self._timeout)
+      threads.append(reraiser_thread.ReraiserThread(new_shard.RunTestsOnShard))
+
+    workers = reraiser_thread.ReraiserThreadGroup(threads)
+    workers.StartAll()
+
+    workers.JoinAll(self._watcher)
+    return results
+
+  # override
+  def TestPackage(self):
+    return 'perf'
+
+  # override
+  def _CreateShards(self, _tests):
+    raise NotImplementedError
+
+  # override
+  def _GetTests(self):
+    return self._test_buckets
+
+  # override
+  def _RunTest(self, _device, _test):
+    raise NotImplementedError
+
+  # override
+  def _ShouldShard(self):
+    return False
+

[jbudorick, 2016/06/28 10:27:32]

nit: +1 line

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+class VersionError(Exception):

[jbudorick, 2016/06/28 10:27:32]

This name should be more specific.

[rnephew (Reviews Here), 2016/06/29 22:27:19]

Done.

+  pass