[Android] Implement perf tests to platform mode.

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

Index: build/android/pylib/local/device/local_device_perf_test_run.py
diff --git a/build/android/pylib/local/device/local_device_perf_test_run.py b/build/android/pylib/local/device/local_device_perf_test_run.py
new file mode 100644
index 0000000000000000000000000000000000000000..ab2a4d63e9d810116f50d491febc0fa022e6eb6b
--- /dev/null
+++ b/build/android/pylib/local/device/local_device_perf_test_run.py
@@ -0,0 +1,360 @@
+# 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

[jbudorick, 2016/06/07 15:29:27]

?

[rnephew (Reviews Here), 2016/06/09 22:06:39]

io is used during the archiving of the output dir.

+import json
+import logging
+import os
+import pickle

[jbudorick, 2016/06/07 15:29:27]

uh oh

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Talked offline.

+import shutil
+import sys
+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.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
+
+
+_BOOTUP_TIMEOUT = 60 * 2

[jbudorick, 2016/06/07 15:29:28]

?

[rnephew (Reviews Here), 2016/06/09 22:06:37]

self._device.WaitUntilFullyBooted(timeout=_BOOTUP_TIMEOUT)

I got rid of that though, and am using devil.android.tools.device_recovery now.

+
+
+class TestShard(object):
+  def __init__(self, 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._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):
+    self._ResetWatcher()
+    self._BatteryLevelCheck()
+    self._BatteryTempCheck()
+    self._ScreenCheck()
+    if not self._device.IsOnline():
+      msg = 'Device %s is unresponsive.' % str(self._device)
+      raise device_errors.DeviceUnreachableError(msg)
+
+  def _TestTearDown(self):
+    try:
+      logging.info('Unmapping device ports.')
+      forwarder.Forwarder.UnmapAllDevicePorts(self._device)
+    except Exception: # pylint: disable=broad-except
+      logging.exception('Exception when resetting ports.')
+
+  def _CleanupOutputDirectory(self):

[jbudorick, 2016/06/07 15:29:27]

This either shouldn't be its own function or it should be defined immediately
next to where it's used. Leaning toward the former.

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Done.

+    if self._output_dir:
+      shutil.rmtree(self._output_dir, ignore_errors=True)
+      self._output_dir = None
+
+  def _CreateCmd(self, test):
+    cmd = '%s --device %s' % (self._tests[test]['cmd'], str(self._device))
+    if (self._test_instance.collect_chartjson_data
+        or self._tests[test].get('archive_output_dir')):
+      self._output_dir = tempfile.mkdtemp()

[jbudorick, 2016/06/07 15:29:27]

This seems like the wrong place for this.

Also, with the way you currently have the retry logic structured, this creates
an output directory on each try but only clears the output directory after all
tries.

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Done.

+      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)
+    timeout = (
+        None if self._test_instance.no_timeout

[jbudorick, 2016/06/07 15:29:26]

When would we want no timeout?

[rnephew (Reviews Here), 2016/06/09 22:06:38]

probably never, but it was a command line option in the old one so I kept it for
feature parity; I can remove it.

+        else self._tests[test].get('timeout', self._timeout))
+    logging.info('Timeout for %s test: %s', test, timeout)
+
+    logfile = sys.stdout

[jbudorick, 2016/06/07 15:29:28]

Why is this set here and not in the GetCmdStatusAndOutputWithTimeout call?

[rnephew (Reviews Here), 2016/06/09 22:06:37]

Artifact of previous changes, its done at the correct place now.

+    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)
+      exit_code, output = cmd_helper.GetCmdStatusAndOutputWithTimeout(

[jbudorick, 2016/06/07 15:29:28]

I'm somewhat worried about muxed output here with sys.stdout going to tests on
all threads.

Also, couldn't we just print the output afterward rather than using logfile?

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Yeah, switched to not passing logfile.

+          cmd, timeout, cwd=cwd, shell=True, logfile=logfile)
+      json_output = self._test_instance.ReadChartjsonOutput(self._output_dir)
+    except cmd_helper.TimeoutError as e:
+      exit_code = -1
+      output = e.output
+      json_output = ''
+    return cmd, exit_code, output, json_output
+
+  def _ProcessTestResult(

[jbudorick, 2016/06/07 15:29:27]

Why doesn't _RunSingleTest handle both running the test and processing the
result? i.e., why doesn't it call _ProcessTestResult?

[rnephew (Reviews Here), 2016/06/09 22:06:38]

No reason it cant, just didnt do it that way; but that seems cleaner so
switching to that.

+      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.
+      try:
+        self._device.WaitUntilFullyBooted(timeout=_BOOTUP_TIMEOUT)
+        self._device.RestartAdbd()
+      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
+
+  def RunTestsOnShard(self):
+    for test in self._tests:
+      try:
+        exit_code = None
+        tries_left = self._retries
+
+        while exit_code != 0 and tries_left > 0:

[jbudorick, 2016/06/07 15:29:28]

Internal retry handling, interesting.

[rnephew (Reviews Here), 2016/06/09 22:06:37]

Acknowledged.

+          self._TestSetUp()
+          self._ResetWatcher()

[jbudorick, 2016/06/07 15:29:26]

This already happens in _TestSetUp?

[rnephew (Reviews Here), 2016/06/09 22:06:37]

I did it afterwards so that there is actually two places for it to time out;
during waiting for charinging/cooling in setup, and actually running the test.

+          tries_left = tries_left - 1
+          start_time = time.time()
+          cmd, exit_code, output, json_output = self._RunSingleTest(test)

[jbudorick, 2016/06/07 15:29:28]

It looks like most of the logic below this should be in a finally block.

[rnephew (Reviews Here), 2016/06/09 22:06:39]

Done.

+          end_time = time.time()
+          result_type = self._ProcessTestResult(
+              test, cmd, start_time, end_time, exit_code, output, json_output)
+          self._TestTearDown()
+
+        result = base_test_result.TestRunResults()
+        result.AddResult(base_test_result.BaseTestResult(test, result_type))
+        self._results.append(result)
+      finally:

[jbudorick, 2016/06/07 15:29:27]

Do we really want a shard to die on exception, especially when retries are
handled internally?

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Fixed.

+        self._CleanupOutputDirectory()
+
+  @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()
+
+  def _ResetWatcher(self):

[jbudorick, 2016/06/07 15:29:28]

This doesn't seem like it needs to be a separate function.

[rnephew (Reviews Here), 2016/06/09 22:06:37]

Done.

+    if self._watcher:
+      self._watcher.Reset()
+
+  def _BatteryLevelCheck(self):
+    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)
+
+  def _ScreenCheck(self):

[jbudorick, 2016/06/07 15:29:28]

Again, doesn't need to be a separate function.

[rnephew (Reviews Here), 2016/06/09 22:06:37]

Done.

+    if not self._device.IsScreenOn():
+      self._device.SetScreen(True)
+
+  def _BatteryTempCheck(self):

[jbudorick, 2016/06/07 15:29:28]

Leaning toward the two battery checks not needing their own functions, either.

[rnephew (Reviews Here), 2016/06/09 22:06:37]

I felt liking doing it made the setup easier to understand/read.

+    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)
+
+
+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):
+    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:

[jbudorick, 2016/06/07 15:29:28]

What happens if neither of these is set?

[rnephew (Reviews Here), 2016/06/09 22:06:38]

It cannot get here without at least one of those set.

+      with file(self._test_instance.steps, 'r') as f:
+        steps = json.load(f)
+        assert steps['version'] == 1

[jbudorick, 2016/06/07 15:29:26]

This should be an exception, but not an assertion.

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Done.

+        return steps
+
+  def _SplitTestsByAffinity(self):
+    test_dict = self._GetStepsFromDict()
+    for test in test_dict['steps']:

[jbudorick, 2016/06/07 15:29:28]

for test, test_config in test_dict['steps'].iteritems():
  affinity = test_config['device_affinity']
  ...

Also, there are a lot of possible KeyErrors in here. We should handle those a
bit more gracefully.

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Done.

+      affinity = test_dict['steps'][test]['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_dict['steps'][test]
+    return self._test_buckets
+
+  @staticmethod
+  def _GetAllDevices(active_devices, devices_path):
+    try:
+      if devices_path:
+        devices = [device_utils.DeviceUtils(s)
+                   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)
+

[jbudorick, 2016/06/07 15:29:28]

nit: one too many empty lines

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Done.

+
+  def _RunOutputJsonList(self):

[jbudorick, 2016/06/07 15:29:28]

This seems like it could be in the test instance...

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Done.

+    if self._test_instance.OutputJsonList() == 0:
+      result_type = base_test_result.ResultType.PASS
+    else:
+      result_type = base_test_result.ResultType.FAIL
+    result = base_test_result.TestRunResults()
+    result.AddResult(
+        base_test_result.BaseTestResult('OutputJsonList', result_type))
+    return [result]
+
+  def _RunPrintStep(self):

[jbudorick, 2016/06/07 15:29:28]

... same.

[rnephew (Reviews Here), 2016/06/09 22:06:37]

I had already moved over a few things, just hadn't gotten them all.

+    if self._test_instance.PrintTestOutput() == 0:
+      result_type = base_test_result.ResultType.PASS
+    else:
+      result_type = base_test_result.ResultType.FAIL
+    result = base_test_result.TestRunResults()
+    result.AddResult(
+        base_test_result.BaseTestResult('PrintStep', result_type))
+    return [result]
+
+  def RunTests(self):
+    # Option selected for saving a json file with a list of test names.
+    if self._test_instance.output_json_list:
+      return self._RunOutputJsonList()
+
+    # Just print the results from a single previously executed step.
+    if self._test_instance.print_step:
+      return self._RunPrintStep()
+
+    # Affinitize the tests.
+    test_buckets = self._SplitTestsByAffinity()
+    if not test_buckets:
+      local_device_test_run.NoTestsError()

[jbudorick, 2016/06/07 15:29:26]

this needs to raise the exception it's creating

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Done.

+    threads = []
+    results = []
+    for x in xrange(min(len(self._devices), len(test_buckets))):
+      new_shard = TestShard(self._test_instance, self._devices[x], x,
+                            test_buckets[x], results, watcher=self._watcher,
+                            retries=self._env.max_tries, timeout=self._timeout)
+      threads.append(reraiser_thread.ReraiserThread(new_shard.RunTestsOnShard))

[jbudorick, 2016/06/07 15:29:27]

Thinking about the parallelizer here.

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Acknowledged.

+
+    workers = reraiser_thread.ReraiserThreadGroup(threads)
+    workers.StartAll()
+
+    try:

[jbudorick, 2016/06/07 15:29:26]

These should be handled on each thread, not on the main one.

Also, you may be interested in @local_device_test_run.handle_shard_failures.

[rnephew (Reviews Here), 2016/06/09 22:06:38]

Done.

+      workers.JoinAll(self._watcher)
+    except device_errors.CommandFailedError:
+      logging.exception('Command failed on device.')
+    except device_errors.CommandTimeoutError:
+      logging.exception('Command timed out on device.')
+    except device_errors.DeviceUnreachableError:
+      logging.exception('Device became unreachable.')
+    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