(Reland) Use logdog butler subcommand to run tests.

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
 
@@ skipping 17 matching lines @@
 TIMEOUT_ANNOTATIONS = [
   ('Manual', 10 * 60 * 60),
   ('IntegrationTest', 30 * 60),
   ('External', 10 * 60),
   ('EnormousTest', 10 * 60),
   ('LargeTest', 5 * 60),
   ('MediumTest', 3 * 60),
   ('SmallTest', 1 * 60),
 ]
 
+LOGCAT_FILTERS = ['*:e', 'chromium:v', 'cr_chromium:v',
+                  'cr_ChromiumAndroidLinker:v', 'cr_LibraryLoader:v',
+                  'cr_LinkerTest:v']
 
 # TODO(jbudorick): Make this private once the instrumentation test_runner is
 # deprecated.
 def DidPackageCrashOnDevice(package_name, device):
   # Dismiss any error dialogs. Limit the number in case we have an error
   # loop or we are failing to dismiss.
   try:
     for _ in xrange(10):
       package = device.DismissCrashDialogIfNeeded()
       if not package:
@@ skipping 236 matching lines @@
           ['log', '-p', 'i', '-t', _TAG, 'START %s' % test_name],
           check_return=True)
       time_ms = lambda: int(time.time() * 1e3)
       start_ms = time_ms()
 
       stream_name = 'logcat_%s_%s_%s' % (
           test_name.replace('#', '.'),
           time.strftime('%Y%m%dT%H%M%S', time.localtime()),
           device.serial)
       logmon = logdog_logcat_monitor.LogdogLogcatMonitor(
-          device.adb, stream_name)
+          device.adb, stream_name, filter_specs=LOGCAT_FILTERS)
+
+      logdog_upload_start = time.time()

[jbudorick, 2017/03/17 19:20:21]

We will not want to include this timing/tracing logic in the final version of
this CL, though it's fine to have it now while we tune the iter_timeout.

[BigBossZhiling, 2017/03/20 22:09:50]

Done.

       with contextlib_ext.Optional(
-          logmon, self._test_instance.should_save_logcat):
+          trace_event.trace('%s_%s' % (test_name, 'including_logdog_upload')),
+          self._env.trace_output):
         with contextlib_ext.Optional(
-            trace_event.trace(test_name),
-            self._env.trace_output):
-          output = device.StartInstrumentation(
-              target, raw=True, extras=extras, timeout=timeout, retries=0)
+            logmon, self._test_instance.should_save_logcat):
+          with contextlib_ext.Optional(
+              trace_event.trace(test_name),
+              self._env.trace_output):
+            test_start = time.time()
+            output = device.StartInstrumentation(
+                target, raw=True, extras=extras, timeout=timeout, retries=0)
+            test_end = time.time()
       logcat_url = logmon.GetLogcatURL()
+      logdog_upload_end = time.time()
+      test_time = test_end - test_start
+      including_logdog_test_time = logdog_upload_end - logdog_upload_start
+      lag_in_logdog = including_logdog_test_time - test_time
+      logging.info('logdog_upload_affects (in second): %0.6f', lag_in_logdog)
     finally:
       device.RunShellCommand(
           ['log', '-p', 'i', '-t', _TAG, 'END %s' % test_name],
           check_return=True)
       duration_ms = time_ms() - start_ms
       if flags:
         self._flag_changers[str(device)].Restore()
       if test_timeout_scale:
         valgrind_tools.SetChromeTimeoutScale(
             device, self._test_instance.timeout_scale)
@@ skipping 112 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