[Android] Log instr test start & end.

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

 # Copyright 2015 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 logging
 import os
 import posixpath
 import re
 import time
 
 from devil.android import device_errors
 from devil.android import flag_changer
 from devil.utils import reraiser_thread
 from pylib import valgrind_tools
 from pylib.base import base_test_result
 from pylib.local.device import local_device_environment
 from pylib.local.device import local_device_test_run
 import tombstones
 
+
+_TAG = 'test_runner_py'
+
 TIMEOUT_ANNOTATIONS = [
   ('Manual', 10 * 60 * 60),
   ('IntegrationTest', 30 * 60),
   ('External', 10 * 60),
   ('EnormousTest', 10 * 60),
   ('LargeTest', 5 * 60),
   ('MediumTest', 3 * 60),
   ('SmallTest', 1 * 60),
 ]
 
@@ skipping 218 matching lines @@
             device, test_timeout_scale * self._test_instance.timeout_scale)
 
     logging.info('preparing to run %s: %s', test_display_name, test)
 
     if flags:
       self._CreateFlagChangerIfNeeded(device)
       self._flag_changers[str(device)].PushFlags(
         add=flags.add, remove=flags.remove)
 
     try:
+      device.RunShellCommand(
+          ['log', '-p', 'i', '-t', _TAG, 'START %s' % test_name],
+          check_return=True)
       time_ms = lambda: int(time.time() * 1e3)
       start_ms = time_ms()
       output = device.StartInstrumentation(
           target, raw=True, extras=extras, timeout=timeout, retries=0)
+    finally:
+      device.RunShellCommand(
+          ['log', '-p', 'i', '-t', _TAG, 'END %s' % test_name],
+          check_return=True)
       duration_ms = time_ms() - start_ms
-    finally:
       if flags:
         self._flag_changers[str(device)].Restore()
       if test_timeout_scale:
         valgrind_tools.SetChromeTimeoutScale(
             device, self._test_instance.timeout_scale)
 
     # TODO(jbudorick): Make instrumentation tests output a JSON so this
     # doesn't have to parse the output.
     result_code, result_bundle, statuses = (
         self._test_instance.ParseAmInstrumentRawOutput(output))
@@ skipping 97 matching lines @@
         timeout = v
         break
     else:
       logging.warning('Using default 1 minute timeout for %s', test_name)
       timeout = 60
 
     timeout *= cls._GetTimeoutScaleFromAnnotations(annotations)
 
     return timeout