Bail out of PhabricatorRepositoryGraphCache more aggressively after cache fills

Summary:
Ref PHI109. Ref T11786. We currently test elapsed time every 64 iterations (since iterations are normally very fast), but at least one install is seeing the page timeout after 30 seconds.

One reason could be that cache fills may occur, and are likely to be much slower than normal iterations. In an extreme case, we could do 64 cache fills before checking the time. Tweak thing so that we always check the time after doing a cache fill, regardless of how many iterations have elapsed since the last attempt.

Additionally, this API method currently accepts an arbitrary number of paths, but implicitly limits each cache query to 500ms. If more than 60 paths are passed, this may exceed 30s. Only let the cache churn for a maximum of 10s across all paths.

If this is more the latter issue than the former, this might replace the GraphCache timeouts with `git` timeouts, but at least our understanding of what's going on here will improve.

Test Plan: This is difficult to test convincingly locally, since I can't reproduce the original issue. It still works after these changes, but it worked fine before these changes too.

Reviewers: amckinley

Reviewed By: amckinley

Maniphest Tasks: T11786

Differential Revision: https://secure.phabricator.com/D18692

src/applications/diffusion/conduit/DiffusionLastModifiedQueryConduitAPIMethod.php

@@ -115,6 +115,10 @@ final class DiffusionLastModifiedQueryConduitAPIMethod
     $graph_cache = new PhabricatorRepositoryGraphCache();
 
     $results = array();
+
+    // Spend no more than this many total seconds trying to satisfy queries
+    // via the graph cache.
+    $remaining_time = 10.0;
     foreach ($map as $path => $commit) {
       $path_id = idx($path_map, $path);
       if (!$path_id) {
@@ -125,13 +129,21 @@ final class DiffusionLastModifiedQueryConduitAPIMethod
         continue;
       }
 
+      $t_start = microtime(true);
       $cache_result = $graph_cache->loadLastModifiedCommitID(
         $commit_id,
-        $path_id);
+        $path_id,
+        $remaining_time);
+      $t_end = microtime(true);
 
       if ($cache_result !== false) {
         $results[$path] = $cache_result;
       }
+
+      $remaining_time -= ($t_end - $t_start);
+      if ($remaining_time <= 0) {
+        break;
+      }
     }
 
     if ($results) {

src/applications/repository/graphcache/PhabricatorRepositoryGraphCache.php

@@ -102,6 +102,10 @@ final class PhabricatorRepositoryGraphCache extends Phobject {
         }
 
         // Otherwise, the rebuild gave us the data, so we can keep going.
+
+        $did_fill = true;
+      } else {
+        $did_fill = false;
       }
 
       // Sanity check so we can survive and recover from bad data.
@@ -147,12 +151,17 @@ final class PhabricatorRepositoryGraphCache extends Phobject {
         $commit_id = $parent_id;
 
         // Periodically check if we've spent too long looking for a result
-        // in the cache, and return so we can fall back to a VCS operation. This
-        // keeps us from having a degenerate worst case if, e.g., the cache
-        // is cold and we need to inspect a very large number of blocks
+        // in the cache, and return so we can fall back to a VCS operation.
+        // This keeps us from having a degenerate worst case if, e.g., the
+        // cache is cold and we need to inspect a very large number of blocks
         // to satisfy the query.
 
-        if (((++$iterations) % 64) === 0) {
+        ++$iterations;
+
+        // If we performed a cache fill in this cycle, always check the time
+        // limit, since cache fills may take a significant amount of time.
+
+        if ($did_fill || ($iterations % 64 === 0)) {
           $t_end = microtime(true);
           if (($t_end - $t_start) > $time) {
             return false;