Output start and end times for perf runs.

build/android/pylib/perf/test_runner.py

 # Copyright 2013 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.
 
 """Runs perf tests.
 
 Our buildbot infrastructure requires each slave to run steps serially.
 This is sub-optimal for android, where these steps can run independently on
 multiple connected devices.
 
@@ skipping 29 matching lines @@
   "step_name_foo",
   "step_name_bar"
 ]
 
 Note that script_to_execute necessarily have to take at least the following
 option:
   --device: the serial number to be passed to all adb commands.
 """
 
 import collections
-import datetime
 import json
 import logging
 import os
 import pickle
 import shutil
 import sys
 import tempfile
 import threading
 import time
 
@@ skipping 19 matching lines @@
 def OutputJsonList(json_input, json_output):
   with file(json_input, 'r') as i:
     all_steps = json.load(i)
 
   step_values = []
   for k, v in all_steps['steps'].iteritems():
     data = {'test': k, 'device_affinity': v['device_affinity']}
 
     persisted_result = GetPersistedResult(k)
     if persisted_result:
+      data['start_time'] = persisted_result['start_time']
+      data['end_time'] = persisted_result['end_time']
       data['total_time'] = persisted_result['total_time']
     step_values.append(data)
 
   with file(json_output, 'w') as o:
     o.write(json.dumps(step_values))
   return 0
 
 
 def PrintTestOutput(test_name, json_file_name=None):
   """Helper method to print the output of previously executed test_name.
@@ skipping 175 matching lines @@
       self._device_battery.LetBatteryCoolToTemperature(
           self._options.max_battery_temp)
 
     logging.info('Charge level: %s%%',
         str(self._device_battery.GetBatteryInfo().get('level')))
     if self._options.min_battery_level:
       self._device_battery.ChargeDeviceToLevel(
           self._options.min_battery_level)
 
     logging.info('%s : %s', test_name, cmd)
-    start_time = datetime.datetime.now()
+    start_time = time.time()
 
     timeout = self._tests['steps'][test_name].get('timeout', 5400)
     if self._options.no_timeout:
       timeout = None
     logging.info('Timeout for %s test: %s', test_name, timeout)
     full_cmd = cmd
     if self._options.dry_run:
       full_cmd = 'echo %s' % cmd
 
     logfile = sys.stdout
     if self._options.single_step:
       # Just print a heart-beat so that the outer buildbot scripts won't timeout
       # without response.
       logfile = _HeartBeatLogger()
     cwd = os.path.abspath(constants.DIR_SOURCE_ROOT)
     if full_cmd.startswith('src/'):
       cwd = os.path.abspath(os.path.join(constants.DIR_SOURCE_ROOT, os.pardir))
     try:
       exit_code, output = cmd_helper.GetCmdStatusAndOutputWithTimeout(
           full_cmd, timeout, cwd=cwd, shell=True, logfile=logfile)
       json_output = self._ReadChartjsonOutput()
     except cmd_helper.TimeoutError as e:
       exit_code = -1
       output = str(e)
       json_output = ''
     finally:
       self._CleanupOutputDirectory()
       if self._options.single_step:
         logfile.stop()
-    end_time = datetime.datetime.now()
+    end_time = time.time()
     if exit_code is None:
       exit_code = -1
     logging.info('%s : exit_code=%d in %d secs at %s',
-                 test_name, exit_code, (end_time - start_time).seconds,
+                 test_name, exit_code, end_time - start_time,
                  self.device_serial)
 
     if exit_code == 0:
       result_type = base_test_result.ResultType.PASS
     else:
       result_type = base_test_result.ResultType.FAIL
       # Since perf tests use device affinity, give the device a chance to
       # recover if it is offline after a failure. Otherwise, the master sharder
       # will remove it from the pool and future tests on this device will fail.
       try:
         self.device.WaitUntilFullyBooted(timeout=120)
       except device_errors.CommandTimeoutError as e:
         logging.error('Device failed to return after %s: %s' % (test_name, e))
 
     actual_exit_code = exit_code
     if test_name in self._flaky_tests:
       # The exit_code is used at the second stage when printing the
       # test output. If the test is flaky, force to "0" to get that step green
       # whilst still gathering data to the perf dashboards.
       # The result_type is used by the test_dispatcher to retry the test.
       exit_code = 0
 
     persisted_result = {
         'name': test_name,
         'output': [output],
         'chartjson': json_output,
         'exit_code': exit_code,
         'actual_exit_code': actual_exit_code,
         'result_type': result_type,
-        'total_time': (end_time - start_time).seconds,
+        'start_time': start_time,
+        'end_time': end_time,
+        'total_time': end_time - start_time,
         'device': self.device_serial,
         'cmd': cmd,
     }
     self._SaveResult(persisted_result)
 
     return (output, result_type)
 
   def RunTest(self, test_name):
     """Run a perf test on the device.
 
     Args:
       test_name: String to use for logging the test result.
 
     Returns:
       A tuple of (TestRunResults, retry).
     """
     _, result_type = self._LaunchPerfTest(test_name)
     results = base_test_result.TestRunResults()
     results.AddResult(base_test_result.BaseTestResult(test_name, result_type))
     retry = None
     if not results.DidRunPass():
       retry = test_name
     return results, retry