detect when changes have been re-queued by developer

This CL teaches the pre-cq-launcher to detect when a CL that was
previously rejected has been re-queued in the CQ, and to record a
timestamped CL action when this takes place. The rationale for doing
this in the pre-cq-launcher is that that builder is continuously running
and examining the validation pool.

BUG=chromium:424037
TEST=New unit test

Change-Id: I393ec4374885669fa20d230da3c03e2387834d5f
Reviewed-on: https://chromium-review.googlesource.com/225865
Reviewed-by: Aviv Keshet <akeshet@chromium.org>
Commit-Queue: Aviv Keshet <akeshet@chromium.org>
Tested-by: Aviv Keshet <akeshet@chromium.org>

3 files changed, 53 insertions, 15 deletions

diff --git a/cbuildbot/constants.py b/cbuildbot/constants.py
index e992c09df..ed5bf635f 100644
--- a/cbuildbot/constants.py
+++ b/cbuildbot/constants.py
@@ -483,9 +483,14 @@ CL_ACTION_PRE_CQ_WAITING = 'pre_cq_waiting'
 CL_ACTION_PRE_CQ_READY_TO_SUBMIT = 'pre_cq_ready_to_submit'
 
 # Miscellaneous actions
-CL_ACTION_REQUEUED = 'requeued'           # Recorded for a change when it is
-                                          # noticed that a previously rejected
-                                          # patch is again in the queue.
+
+# Recorded by pre-cq launcher for a change when it is noticed that a previously
+# rejected change is again in the queue.
+# This is a best effort detection for developers re-marking their changes, to
+# help calculate true CQ handling time. It is susceptible to developers
+# un-marking their change after is requeued or to the CQ picking up a CL before
+# it is seen by the pre-cq-launcher.
+CL_ACTION_REQUEUED = 'requeued'
 
 # Recorded by pre-cq launcher when it has screened a change for necessary
 # tryjobs
diff --git a/cbuildbot/stages/sync_stages.py b/cbuildbot/stages/sync_stages.py
index 4f260171c..05c9da5b9 100644
--- a/cbuildbot/stages/sync_stages.py
+++ b/cbuildbot/stages/sync_stages.py
@@ -1111,11 +1111,18 @@ class PreCQLauncherStage(SyncStage):
     """
     # Get change status.
     status_map = {}
-    _, db = self._run.GetCIDBHandle()
+    build_id, db = self._run.GetCIDBHandle()
     action_history = db.GetActionsForChanges(changes)
     for change in changes:
       status = clactions.GetCLPreCQStatus(change, action_history)
       status_map[change] = status
+      # Detect changes that have been re-queued by the developer, and mark
+      # them as such in cidb.
+      was_requeued = clactions.WasChangeRequeued(change, action_history)
+      if was_requeued:
+        action = clactions.CLAction.FromGerritPatchAndAction(
+            change, constants.CL_ACTION_REQUEUED)
+        db.InsertCLActions(build_id, [action])
 
     # Launch trybots for manifest changes.
     for plan in self.GetDisjointTransactionsToTest(pool, changes, status_map):
diff --git a/cbuildbot/stages/sync_stages_unittest.py b/cbuildbot/stages/sync_stages_unittest.py
index be97b9524..efe51af2a 100755
--- a/cbuildbot/stages/sync_stages_unittest.py
+++ b/cbuildbot/stages/sync_stages_unittest.py
@@ -180,7 +180,7 @@ class BaseCQTestCase(generic_stages_unittest.StageTest):
   def PerformSync(self, committed=False, num_patches=1, tree_open=True,
                   tree_throttled=False,
                   pre_cq_status=constants.CL_STATUS_PASSED,
-                  runs=0, **kwargs):
+                  runs=0, changes=None, **kwargs):
     """Helper to perform a basic sync for master commit queue.
 
     Args:
@@ -194,6 +194,9 @@ class BaseCQTestCase(generic_stages_unittest.StageTest):
       runs: The maximum number of times to allow validation_pool.AcquirePool
             to wait for additional changes. runs=0 means never wait for
             additional changes. Default: 0.
+      changes: Optional list of MockPatch instances that should be available
+               in validation pool. If not specified, a set of |num_patches|
+               patches will be created.
       **kwargs: Additional arguments to pass to MockPatch when creating patches.
 
     Returns:
@@ -201,7 +204,7 @@ class BaseCQTestCase(generic_stages_unittest.StageTest):
     """
     kwargs.setdefault('approval_timestamp',
         time.time() - sync_stages.PreCQLauncherStage.LAUNCH_DELAY * 60)
-    changes = [MockPatch(**kwargs)] * num_patches
+    changes = changes or [MockPatch(**kwargs)] * num_patches
     if pre_cq_status is not None:
       new_build_id = self.fake_db.InsertBuild('Pre cq group',
                                               constants.WATERFALL_TRYBOT,
@@ -288,15 +291,18 @@ class MasterCQSyncTestCase(BaseCQTestCase):
     """
     return self._testCommitNonManifestChange(committed=False)
 
-  def _testCommitManifestChange(self, **kwargs):
+  def _testCommitManifestChange(self, changes=None, **kwargs):
     """Test committing a change to a project that's part of the manifest.
 
+    Args:
+      changes: Optional list of MockPatch instances to use in PerformSync.
+
     Returns:
       List of MockPatch objects that were used in PerformSync
     """
     self.PatchObject(validation_pool.ValidationPool, '_FilterNonCrosProjects',
                      side_effect=lambda x, _: (x, []))
-    return self.PerformSync(**kwargs)
+    return self.PerformSync(changes=changes, **kwargs)
 
   def _testDefaultSync(self):
     """Test basic ability to sync with standard options.
@@ -458,16 +464,20 @@ class PreCQLauncherStageTest(MasterCQSyncTestCase):
     action_history = self.fake_db.GetActionsForChanges([change])
     return clactions.GetCLPreCQStatus(change, action_history)
 
-  def runTrybotTest(self, launching=0, waiting=0, failed=0, runs=0):
+  def runTrybotTest(self, launching=0, waiting=0, failed=0, runs=0,
+                    change=None):
     """Helper function for testing PreCQLauncher.
 
-    Create a mock patch to be picked up by the PreCQ. Allow up to
-    |runs|+1 calls to ProcessChanges. Assert that the patch received status
-    LAUNCHING, WAITING, and FAILED |launching|, |waiting|, and |failed| times
-    respectively.
+    Create a mock patch to be picked up by the PreCQ (or use |change| if it is
+    specified. Allow up to |runs|+1 calls to ProcessChanges. Assert that the
+    patch received status LAUNCHING, WAITING, and FAILED |launching|,
+    |waiting|, and |failed| times respectively.
     """
-    change = self._testCommitManifestChange(pre_cq_status=None, runs=runs)[0]
-
+    changes = None
+    if change:
+      changes = [change]
+    change = self._testCommitManifestChange(changes=changes, pre_cq_status=None,
+                                            runs=runs)[0]
     # Count the number of recorded actions corresponding to launching, watiting,
     # and failed, and ensure they are correct.
     expected = (launching, waiting, failed)
@@ -512,6 +522,22 @@ class PreCQLauncherStageTest(MasterCQSyncTestCase):
     self.runTrybotTest(runs=1)
     m.assert_called_with([mock.ANY], check_tree_open=False)
 
+  def testRequeued(self):
+    """Test that a previously rejected patch gets marked as requeued."""
+    p = MockPatch()
+    previous_build_id = self.fake_db.InsertBuild(
+        'some name', constants.WATERFALL_TRYBOT, 1, 'some_config',
+        'some_hostname')
+    action = clactions.CLAction.FromGerritPatchAndAction(
+        p, constants.CL_ACTION_KICKED_OUT)
+    self.fake_db.InsertCLActions(previous_build_id, [action])
+    self.runTrybotTest(launching=1, change=p)
+
+    actions_for_patch = self.fake_db.GetActionsForChanges([p])
+    requeued_actions = [a for a in actions_for_patch
+                        if a.action == constants.CL_ACTION_REQUEUED]
+    self.assertEqual(1, len(requeued_actions))
+
 
 if __name__ == '__main__':
   cros_test_lib.main()