[Autotest] Time the staging of control files.

To debug some apache slowness this cl times the staging/parsing of
control files. This operation is the main suspect for the slowness
of the create_suite_job rpc.

TEST=Executed the rpc.
BUG=None
DEPLOY=apache

Change-Id: I3c3892054a33a52dd31d467567b09862395dc91b
Reviewed-on: https://chromium-review.googlesource.com/231079
Reviewed-by: Prashanth B <beeps@chromium.org>
Commit-Queue: Prashanth B <beeps@chromium.org>
Tested-by: Prashanth B <beeps@chromium.org>
diff --git a/frontend/afe/site_rpc_interface.py b/frontend/afe/site_rpc_interface.py
index 618841e..68c0bd1 100644
--- a/frontend/afe/site_rpc_interface.py
+++ b/frontend/afe/site_rpc_interface.py
@@ -60,9 +60,14 @@
     @return the contents of the desired control file.
     """
     getter = control_file_getter.DevServerGetter.create(build, ds)
+    timer = stats.Timer('control_files.parse.%s.%s' %
+                        (ds.get_server_name(ds.url()).replace('.', '_'),
+                            suite_name.rsplit('.')[-1]))
     # Get the control file for the suite.
     try:
-        control_file_in = getter.get_control_file_contents_by_name(suite_name)
+        with timer:
+            control_file_in = getter.get_control_file_contents_by_name(
+                    suite_name)
     except error.CrosDynamicSuiteException as e:
         raise type(e)("%s while testing %s." % (e, build))
     if not control_file_in:
@@ -95,8 +100,11 @@
     # components to be downloaded in the background.
     ds = dev_server.ImageServer.resolve(build)
     timings[constants.DOWNLOAD_STARTED_TIME] = formatted_now()
+    timer = stats.Timer('control_files.stage.%s' % (
+                    ds.get_server_name(ds.url()).replace('.', '_')))
     try:
-        ds.stage_artifacts(build, ['test_suites'])
+        with timer:
+            ds.stage_artifacts(build, ['test_suites'])
     except dev_server.DevServerException as e:
         raise error.StageControlFileFailure(
                 "Failed to stage %s: %s" % (build, e))
diff --git a/frontend/afe/site_rpc_interface_unittest.py b/frontend/afe/site_rpc_interface_unittest.py
index 164cad0..e3a068a 100644
--- a/frontend/afe/site_rpc_interface_unittest.py
+++ b/frontend/afe/site_rpc_interface_unittest.py
@@ -111,6 +111,9 @@
     def testStageBuildFail(self):
         """Ensure that a failure to stage the desired build fails the RPC."""
         self._setupDevserver()
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.dev_server.stage_artifacts(
             self._BUILD, ['test_suites']).AndRaise(
                 dev_server.DevServerException())
@@ -126,8 +129,14 @@
     def testGetControlFileFail(self):
         """Ensure that a failure to get needed control file fails the RPC."""
         self._mockDevServerGetter()
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.dev_server.stage_artifacts(self._BUILD,
                                         ['test_suites']).AndReturn(True)
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.getter.get_control_file_contents_by_name(
             self._SUITE_NAME).AndReturn(None)
         self.mox.ReplayAll()
@@ -142,8 +151,14 @@
     def testGetControlFileListFail(self):
         """Ensure that a failure to get needed control file fails the RPC."""
         self._mockDevServerGetter()
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.dev_server.stage_artifacts(self._BUILD,
                                         ['test_suites']).AndReturn(True)
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.getter.get_control_file_contents_by_name(
             self._SUITE_NAME).AndRaise(error.NoControlFileList())
         self.mox.ReplayAll()
@@ -184,11 +199,18 @@
     def testCreateSuiteJobFail(self):
         """Ensure that failure to schedule the suite job fails the RPC."""
         self._mockDevServerGetter()
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.dev_server.stage_artifacts(self._BUILD,
                                         ['test_suites']).AndReturn(True)
+
         self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.getter.get_control_file_contents_by_name(
             self._SUITE_NAME).AndReturn('f')
+
+        self.dev_server.url().AndReturn('mox_url')
         self._mockRpcUtils(-1)
         self.mox.ReplayAll()
         self.assertEquals(
@@ -201,11 +223,18 @@
     def testCreateSuiteJobSuccess(self):
         """Ensures that success results in a successful RPC."""
         self._mockDevServerGetter()
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.dev_server.stage_artifacts(self._BUILD,
                                         ['test_suites']).AndReturn(True)
+
         self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.getter.get_control_file_contents_by_name(
             self._SUITE_NAME).AndReturn('f')
+
+        self.dev_server.url().AndReturn('mox_url')
         job_id = 5
         self._mockRpcUtils(job_id)
         self.mox.ReplayAll()
@@ -220,11 +249,18 @@
     def testCreateSuiteJobNoHostCheckSuccess(self):
         """Ensures that success results in a successful RPC."""
         self._mockDevServerGetter()
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.dev_server.stage_artifacts(self._BUILD,
                                         ['test_suites']).AndReturn(True)
+
         self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.getter.get_control_file_contents_by_name(
             self._SUITE_NAME).AndReturn('f')
+
+        self.dev_server.url().AndReturn('mox_url')
         job_id = 5
         self._mockRpcUtils(job_id)
         self.mox.ReplayAll()
@@ -238,11 +274,18 @@
     def testCreateSuiteIntegerNum(self):
         """Ensures that success results in a successful RPC."""
         self._mockDevServerGetter()
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.dev_server.stage_artifacts(self._BUILD,
                                         ['test_suites']).AndReturn(True)
+
         self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.getter.get_control_file_contents_by_name(
             self._SUITE_NAME).AndReturn('f')
+
+        self.dev_server.url().AndReturn('mox_url')
         job_id = 5
         self._mockRpcUtils(job_id, control_file_substring='num=17')
         self.mox.ReplayAll()
@@ -259,6 +302,9 @@
     def testCreateSuiteJobControlFileSupplied(self):
         """Ensure we can supply the control file to create_suite_job."""
         self._mockDevServerGetter(get_control_file=False)
+
+        self.dev_server.url().AndReturn('mox_url')
+        self.dev_server.get_server_name(mox.IgnoreArg()).AndReturn('mox_url')
         self.dev_server.stage_artifacts(self._BUILD,
                                         ['test_suites']).AndReturn(True)
         self.dev_server.url().AndReturn('mox_url')