Report android emulator timing on installing CIPD and serial listening.

So that we can keep track of these time and optimize the script.

Bug: 343242386
Change-Id: Icbcb4ebd836330fe54c13cabd41bf3d1bc1c5333
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/6388197
Commit-Queue: Haiyang Pan <hypan@google.com>
Reviewed-by: Nate Fischer <ntfschr@chromium.org>
Reviewed-by: Andrew Grieve <agrieve@chromium.org>
Cr-Commit-Position: refs/heads/main@{#1437813}

android_webview/tools/run_cts.pydeps

@@ -16,8 +16,16 @@
 //build/gn_helpers.py
 //build/util/lib/__init__.py
 //build/util/lib/proto/__init__.py
+//build/util/lib/proto/average.py
+//build/util/lib/proto/count.py
+//build/util/lib/proto/data_points.py
 //build/util/lib/proto/exception_occurrences_pb2.py
 //build/util/lib/proto/exception_recorder.py
+//build/util/lib/proto/measure.py
+//build/util/lib/proto/measures.py
+//build/util/lib/proto/metric.py
+//build/util/lib/proto/test_script_metrics_pb2.py
+//build/util/lib/proto/time_consumption.py
 //third_party/catapult/common/py_utils/py_utils/__init__.py
 //third_party/catapult/common/py_utils/py_utils/cloud_storage.py
 //third_party/catapult/common/py_utils/py_utils/cloud_storage_global_lock.py

build/android/pylib/local/emulator/avd.py

@@ -30,6 +30,7 @@ from pylib.local.emulator import ini
 from pylib.local.emulator.proto import avd_pb2
 
 from lib.proto import exception_recorder
+from lib.proto import measures
 
 # A common root directory to store the CIPD packages for creating or starting
 # the emulator instance, e.g. emulator binary, system images, AVDs.
@@ -844,7 +845,8 @@ class AvdConfig:
     Returns: None
     Raises: AvdException on failure to install.
     """
-    self._InstallCipdPackages(_PACKAGES_RUNTIME)
+    with measures.time_consumption('emulator', 'install', 'cipd_packages'):
+      self._InstallCipdPackages(_PACKAGES_RUNTIME)
     self._MakeWriteable()
     self._UpdateConfigs()
     self._RebaseQcow2Images()
@@ -1204,12 +1206,14 @@ class _AvdInstance:
           return 'emulator-%d' % int(val)
 
       try:
-        self._emulator_serial = timeout_retry.Run(
-            listen_for_serial,
-            timeout=300 if is_slow_start else 60,
-            retries=retries,
-            args=[sock])
-        logging.info('%s started', self._emulator_serial)
+        with measures.time_consumption('emulator', 'start',
+                                       'listen_for_serial'):
+          self._emulator_serial = timeout_retry.Run(
+              listen_for_serial,
+              timeout=300 if is_slow_start else 60,
+              retries=retries,
+              args=[sock])
+          logging.info('%s started', self._emulator_serial)
       except base_error.BaseError as e:
         self.Stop(force=True)
         raise AvdStartException(str(e)) from e

build/android/test_runner.py

@@ -57,6 +57,7 @@ from pylib.utils import test_filter
 from py_utils import contextlib_ext
 
 from lib.proto import exception_recorder
+from lib.proto import measures
 from lib.results import result_sink
 
 _DEVIL_STATIC_CONFIG_FILE = os.path.abspath(os.path.join(
@@ -1051,36 +1052,51 @@ _SUPPORTED_IN_PLATFORM_MODE = [
 ]
 
 
-def UploadExceptions(result_sink_client, exc_recorder):
-  if not result_sink_client or not exc_recorder.size():
+def UploadTestScriptRecords(result_sink_client, exc_recorder, mm_recorder):
+  '''Upload test script data, i.e. exceptions and metrics to ResultDB.
+
+  Args:
+    result_sink_client: A ResultSinkClient object
+    exc_recorder: The module to create and manage exception records.
+    mm_recorder: The module to create and manage measure records.
+  '''
+  if not result_sink_client:
+    return
+  if not exc_recorder.size() and not mm_recorder.size():
     return
 
   try_count_max = 3
   for try_count in range(1, try_count_max + 1):
-    logging.info('Uploading exception records to RDB. (TRY %d/%d)', try_count,
+    logging.info('Uploading test script records to RDB. (TRY %d/%d)', try_count,
                  try_count_max)
     try:
-      record_dict = exc_recorder.to_dict()
-      result_sink_client.UpdateInvocationExtendedProperties(
-          {exc_recorder.EXCEPTION_OCCURRENCES_KEY: record_dict})
+      records = {}
+      if exc_recorder.size():
+        records[exc_recorder.EXCEPTION_OCCURRENCES_KEY] = exc_recorder.to_dict()
+      if mm_recorder.size():
+        records[mm_recorder.TEST_SCRIPT_METRICS_KEY] = mm_recorder.to_dict()
+      result_sink_client.UpdateInvocationExtendedProperties(records)
       exc_recorder.clear()
+      mm_recorder.clear()
       break
     except Exception as e:  # pylint: disable=W0703
-      logging.error("Got error %s when uploading exception records.", e)
+      logging.error("Got error %s when uploading test script records.", e)
       # Upload can fail due to record size being too big.
       # In this case, let's try to reduce the size.
       if try_count == try_count_max - 2:
         # Clear all the stackstrace to reduce size.
         exc_recorder.clear_stacktrace()
       elif try_count == try_count_max - 1:
-        # Clear all the records and just report the upload failure.
+        # For the exception recorder, clear all the records and just report
+        # the upload failure.
         exc_recorder.clear()
         exc_recorder.register(e)
       elif try_count == try_count_max:
-        # Swallow the exception if the upload fails again and hit the max
+        # Swallow all the records if the upload fails again and hit the max
         # try so that it won't fail the test task (and it shouldn't).
         exc_recorder.clear()
-        logging.error("Hit max retry. Skip uploading exception records.")
+        mm_recorder.clear()
+        logging.error("Hit max retry. Skip uploading test script records.")
 
 
 def RunTestsInPlatformMode(args, result_sink_client=None):
@@ -1211,11 +1227,11 @@ def RunTestsInPlatformMode(args, result_sink_client=None):
                            ) and not args.isolated_script_test_output
 
   @contextlib.contextmanager
-  def exceptions_uploader():
+  def test_script_records_uploader():
     try:
       yield
     finally:
-      UploadExceptions(result_sink_client, exception_recorder)
+      UploadTestScriptRecords(result_sink_client, exception_recorder, measures)
 
   ### Set up test objects.
 
@@ -1255,7 +1271,7 @@ def RunTestsInPlatformMode(args, result_sink_client=None):
     # |raw_logs_fh| is only used by Robolectric tests.
     raw_logs_fh = io.StringIO() if save_detailed_results else None
 
-    with json_writer(), exceptions_uploader(), logcats_uploader, \
+    with json_writer(), test_script_records_uploader(), logcats_uploader, \
          env, test_instance, test_run:
 
       repetitions = (range(args.repeat +

build/android/test_runner.pydeps

@@ -139,8 +139,16 @@
 ../util/lib/common/chrome_test_server_spawner.py
 ../util/lib/common/unittest_util.py
 ../util/lib/proto/__init__.py
+../util/lib/proto/average.py
+../util/lib/proto/count.py
+../util/lib/proto/data_points.py
 ../util/lib/proto/exception_occurrences_pb2.py
 ../util/lib/proto/exception_recorder.py
+../util/lib/proto/measure.py
+../util/lib/proto/measures.py
+../util/lib/proto/metric.py
+../util/lib/proto/test_script_metrics_pb2.py
+../util/lib/proto/time_consumption.py
 ../util/lib/results/__init__.py
 ../util/lib/results/result_sink.py
 ../util/lib/results/result_types.py

build/android/test_runner_test.py

@@ -11,54 +11,70 @@ from unittest import mock
 import test_runner
 
 
-class UploadExceptionTest(unittest.TestCase):
+class UploadTestScriptRecordsTest(unittest.TestCase):
 
   def setUp(self):
     self.sink_client = mock.MagicMock()
     self.exc_recorder = mock.MagicMock()
+    self.mm_recorder = mock.MagicMock()
 
-  def testNoExceptions(self):
+  def testNoRecords(self):
     self.exc_recorder.size.return_value = 0
-    test_runner.UploadExceptions(self.sink_client, self.exc_recorder)
+    self.mm_recorder.size.return_value = 0
+    test_runner.UploadTestScriptRecords(self.sink_client, self.exc_recorder,
+                                        self.mm_recorder)
     self.exc_recorder.to_dict.assert_not_called()
+    self.mm_recorder.to_dict.assert_not_called()
     self.sink_client.UpdateInvocationExtendedProperties.assert_not_called()
 
   def testUploadSuccess(self):
-    test_runner.UploadExceptions(self.sink_client, self.exc_recorder)
+    test_runner.UploadTestScriptRecords(self.sink_client, self.exc_recorder,
+                                        self.mm_recorder)
     self.exc_recorder.to_dict.assert_called_once()
+    self.mm_recorder.to_dict.assert_called_once()
     self.sink_client.UpdateInvocationExtendedProperties.assert_called_once()
     self.exc_recorder.clear.assert_called_once()
+    self.mm_recorder.clear.assert_called_once()
 
   def testUploadSuccessWithClearStacktrace(self):
     self.sink_client.UpdateInvocationExtendedProperties.side_effect = [
         Exception("Error 1"), None
     ]
-    test_runner.UploadExceptions(self.sink_client, self.exc_recorder)
+    test_runner.UploadTestScriptRecords(self.sink_client, self.exc_recorder,
+                                        self.mm_recorder)
     self.assertEqual(self.exc_recorder.to_dict.call_count, 2)
+    self.assertEqual(self.mm_recorder.to_dict.call_count, 2)
     self.assertEqual(
         self.sink_client.UpdateInvocationExtendedProperties.call_count, 2)
     self.exc_recorder.clear_stacktrace.assert_called_once()
     self.exc_recorder.clear.assert_called_once()
+    self.mm_recorder.clear.assert_called_once()
 
   def testUploadSuccessWithClearRecords(self):
     self.sink_client.UpdateInvocationExtendedProperties.side_effect = [
         Exception("Error 1"), Exception("Error 2"), None
     ]
-    test_runner.UploadExceptions(self.sink_client, self.exc_recorder)
+    test_runner.UploadTestScriptRecords(self.sink_client, self.exc_recorder,
+                                        self.mm_recorder)
     self.assertEqual(self.exc_recorder.to_dict.call_count, 3)
+    self.assertEqual(self.mm_recorder.to_dict.call_count, 3)
     self.assertEqual(
         self.sink_client.UpdateInvocationExtendedProperties.call_count, 3)
     self.exc_recorder.clear_stacktrace.assert_called_once()
     self.assertEqual(self.exc_recorder.clear.call_count, 2)
     self.exc_recorder.register.assert_called_once()
+    self.mm_recorder.clear.assert_called_once()
 
   def testUploadFailure(self):
     self.sink_client.UpdateInvocationExtendedProperties.side_effect = (
         Exception("Error"))
-    test_runner.UploadExceptions(self.sink_client, self.exc_recorder)
+    test_runner.UploadTestScriptRecords(self.sink_client, self.exc_recorder,
+                                        self.mm_recorder)
     self.assertEqual(self.exc_recorder.to_dict.call_count, 3)
+    self.assertEqual(self.mm_recorder.to_dict.call_count, 3)
     self.assertEqual(
         self.sink_client.UpdateInvocationExtendedProperties.call_count, 3)
     self.assertEqual(self.exc_recorder.clear.call_count, 2)
     self.exc_recorder.clear_stacktrace.assert_called_once()
     self.exc_recorder.register.assert_called_once()
+    self.mm_recorder.clear.assert_called_once()

build/util/lib/proto/measures.py

@@ -7,10 +7,14 @@
 
 import json
 import os
+import sys
 
 from google.protobuf import any_pb2
 from google.protobuf.json_format import MessageToDict
 
+# Add to sys.path so that this module can be imported by other modules that
+# have different path setup, e.g. android test runner, and ios test runner.
+sys.path.append(os.path.abspath(os.path.dirname(__file__)))
 from average import Average
 from count import Count
 from data_points import DataPoints