launchpad-reviewers team mailing list archive

[Colin Watson <cjwatson@xxxxxxxxxxxxx>]

Colin Watson has proposed merging lp:~cjwatson/launchpad/git-ref-tolerate-slow-commit-info into lp:launchpad.

Commit message:
Tolerate backend timeouts while fetching commit information for GitRef:+index.

Requested reviews:
  Launchpad code reviewers (launchpad-reviewers)
Related bugs:
  Bug #1804395 in Launchpad itself: "Timeouts when accessing repo branches"
  https://bugs.launchpad.net/launchpad/+bug/1804395

For more details, see:
https://code.launchpad.net/~cjwatson/launchpad/git-ref-tolerate-slow-commit-info/+merge/359827
-- 
Your team Launchpad code reviewers is requested to review the proposed merge of lp:~cjwatson/launchpad/git-ref-tolerate-slow-commit-info into lp:launchpad.

=== modified file 'lib/lp/code/browser/gitref.py'
--- lib/lp/code/browser/gitref.py	2018-08-30 14:54:37 +0000
+++ lib/lp/code/browser/gitref.py	2018-11-29 12:18:57 +0000
@@ -49,6 +49,7 @@
 from lp.code.interfaces.gitrepository import IGitRepositorySet
 from lp.services.helpers import english_list
 from lp.services.propertycache import cachedproperty
+from lp.services.scripts import log
 from lp.services.webapp import (
     canonical_url,
     ContextMenu,
@@ -180,7 +181,7 @@
     @cachedproperty
     def commit_infos(self):
         return self.context.getLatestCommits(
-            extended_details=True, user=self.user)
+            extended_details=True, user=self.user, logger=log)
 
     @property
     def recipes_link(self):

=== modified file 'lib/lp/code/browser/tests/test_gitref.py'
--- lib/lp/code/browser/tests/test_gitref.py	2018-09-27 13:50:06 +0000
+++ lib/lp/code/browser/tests/test_gitref.py	2018-11-29 12:18:57 +0000
@@ -11,10 +11,14 @@
 import hashlib
 import re
 
+from fixtures import FakeLogger
 import pytz
 import soupmatchers
 from storm.store import Store
-from testtools.matchers import Equals
+from testtools.matchers import (
+    Equals,
+    Not,
+    )
 from zope.component import getUtility
 from zope.security.proxy import removeSecurityProxy
 
@@ -23,6 +27,7 @@
 from lp.code.tests.helpers import GitHostingFixture
 from lp.services.beautifulsoup import BeautifulSoup
 from lp.services.job.runner import JobRunner
+from lp.services.timeout import TimeoutError
 from lp.services.utils import seconds_since_epoch
 from lp.services.webapp.publisher import canonical_url
 from lp.testing import (
@@ -82,6 +87,14 @@
             canonical_url(ref))
 
 
+class MissingCommitsNote(soupmatchers.Tag):
+
+    def __init__(self):
+        super(MissingCommitsNote, self).__init__(
+            "missing commits note", "div",
+            text="Some recent commit information could not be fetched.")
+
+
 class TestGitRefView(BrowserTestCase):
 
     layer = LaunchpadFunctionalLayer
@@ -186,11 +199,12 @@
         self.hosting_fixture.getLog.result = list(reversed(log))
         self.scanRef(ref, log[-1])
         view = create_initialized_view(ref, "+index")
+        contents = view()
         expected_texts = list(reversed([
             "%.7s...\nby\n%s\non 2015-01-%02d" % (
                 log[i]["sha1"], log[i]["author"]["name"], i + 1)
             for i in range(5)]))
-        details = find_tags_by_class(view(), "commit-details")
+        details = find_tags_by_class(contents, "commit-details")
         self.assertEqual(
             expected_texts, [extract_text(detail) for detail in details])
         expected_urls = list(reversed([
@@ -199,6 +213,8 @@
             for i in range(5)]))
         self.assertEqual(
             expected_urls, [detail.a["href"] for detail in details])
+        self.assertThat(
+            contents, Not(soupmatchers.HTMLContains(MissingCommitsNote())))
 
     def test_recent_commits_with_merge(self):
         [ref] = self.factory.makeGitRefs(paths=["refs/heads/branch"])
@@ -211,7 +227,8 @@
         self.scanRef(mp.merge_source, merged_tip)
         mp.markAsMerged(merged_revision_id=log[0]["sha1"])
         view = create_initialized_view(ref, "+index")
-        soup = BeautifulSoup(view())
+        contents = view()
+        soup = BeautifulSoup(contents)
         details = soup.findAll(
             attrs={"class": re.compile(r"commit-details|commit-comment")})
         expected_texts = list(reversed([
@@ -225,6 +242,8 @@
         self.assertEqual(
             [canonical_url(mp), canonical_url(mp.merge_source)],
             [link["href"] for link in details[5].findAll("a")])
+        self.assertThat(
+            contents, Not(soupmatchers.HTMLContains(MissingCommitsNote())))
 
     def test_recent_commits_with_merge_from_deleted_ref(self):
         [ref] = self.factory.makeGitRefs(paths=["refs/heads/branch"])
@@ -238,7 +257,8 @@
         mp.markAsMerged(merged_revision_id=log[0]["sha1"])
         mp.source_git_repository.removeRefs([mp.source_git_path])
         view = create_initialized_view(ref, "+index")
-        soup = BeautifulSoup(view())
+        contents = view()
+        soup = BeautifulSoup(contents)
         details = soup.findAll(
             attrs={"class": re.compile(r"commit-details|commit-comment")})
         expected_texts = list(reversed([
@@ -252,6 +272,8 @@
         self.assertEqual(
             [canonical_url(mp)],
             [link["href"] for link in details[5].findAll("a")])
+        self.assertThat(
+            contents, Not(soupmatchers.HTMLContains(MissingCommitsNote())))
 
     def _test_all_commits_link(self, branch_name, encoded_branch_name=None):
         if encoded_branch_name is None:
@@ -312,3 +334,22 @@
         with StormStatementRecorder() as recorder:
             view.landing_targets
         self.assertThat(recorder, HasQueryCount(Equals(12)))
+
+    def test_timeout(self):
+        # The page renders even if fetching commits times out.
+        self.useFixture(FakeLogger())
+        [ref] = self.factory.makeGitRefs()
+        log = self.makeCommitLog()
+        self.scanRef(ref, log[-1])
+        self.hosting_fixture.getLog.failure = TimeoutError
+        view = create_initialized_view(ref, "+index")
+        contents = view()
+        soup = BeautifulSoup(contents)
+        details = soup.findAll(
+            attrs={"class": re.compile(r"commit-details|commit-comment")})
+        expected_text = "%.7s...\nby\n%s\non 2015-01-%02d" % (
+            log[-1]["sha1"], log[-1]["author"]["name"], len(log))
+        self.assertEqual(
+            [expected_text], [extract_text(detail) for detail in details])
+        self.assertThat(
+            contents, soupmatchers.HTMLContains(MissingCommitsNote()))

=== modified file 'lib/lp/code/interfaces/gitref.py'
--- lib/lp/code/interfaces/gitref.py	2018-10-25 17:52:43 +0000
+++ lib/lp/code/interfaces/gitref.py	2018-11-29 12:18:57 +0000
@@ -364,7 +364,8 @@
         "yet been scanned.")
 
     def getCommits(start, limit=None, stop=None, union_repository=None,
-                   start_date=None, end_date=None, logger=None):
+                   start_date=None, end_date=None, handle_timeout=False,
+                   logger=None):
         """Get commit information from this reference.
 
         :param start: The commit to start listing from.
@@ -374,11 +375,14 @@
             this repository as well (particularly useful with `stop`).
         :param start_date: If not None, ignore commits before this date.
         :param end_date: If not None, ignore commits after this date.
+        :param handle_timeout: If True and the backend request times out,
+            synthesise commit information from what we have in the database.
         :param logger: An optional logger.
         :return: An iterable of commit information dicts.
         """
 
-    def getLatestCommits(quantity=10):
+    def getLatestCommits(quantity=10, extended_details=False, user=None,
+                         logger=None):
         """Return a specific number of the latest commits in this ref."""
 
     has_commits = Attribute("Whether this reference has any commits.")

=== modified file 'lib/lp/code/model/gitref.py'
--- lib/lp/code/model/gitref.py	2018-11-09 22:06:43 +0000
+++ lib/lp/code/model/gitref.py	2018-11-29 12:18:57 +0000
@@ -82,7 +82,11 @@
 from lp.services.database.stormbase import StormBase
 from lp.services.features import getFeatureFlag
 from lp.services.memcache.interfaces import IMemcacheClient
-from lp.services.timeout import urlfetch
+from lp.services.timeout import (
+    reduced_timeout,
+    TimeoutError,
+    urlfetch,
+    )
 from lp.services.utils import seconds_since_epoch
 from lp.services.webapp.interfaces import ILaunchBag
 
@@ -336,9 +340,10 @@
                 try:
                     log = json.loads(cached_log)
                 except Exception:
-                    logger.exception(
-                        "Cannot load cached log information for %s:%s; "
-                        "deleting" % (path, start))
+                    if logger is not None:
+                        logger.exception(
+                            "Cannot load cached log information for %s:%s; "
+                            "deleting" % (path, start))
                     memcache_client.delete(memcache_key)
         if log is None:
             if enable_hosting:
@@ -367,19 +372,38 @@
         return log
 
     def getCommits(self, start, limit=None, stop=None, union_repository=None,
-                   start_date=None, end_date=None, logger=None):
+                   start_date=None, end_date=None, handle_timeout=False,
+                   logger=None):
         # Circular import.
         from lp.code.model.gitrepository import parse_git_commits
 
-        log = self._getLog(
-            start, limit=limit, stop=stop, union_repository=union_repository,
-            logger=logger)
-        parsed_commits = parse_git_commits(log)
+        with reduced_timeout(1.0 if handle_timeout else 0.0):
+            try:
+                log = self._getLog(
+                    start, limit=limit, stop=stop,
+                    union_repository=union_repository, logger=logger)
+                commit_oids = [
+                    commit["sha1"] for commit in log if "sha1" in commit]
+                parsed_commits = parse_git_commits(log)
+            except TimeoutError:
+                if not handle_timeout:
+                    raise
+                if logger is not None:
+                    logger.exception(
+                        "Timeout fetching commits for %s" % self.identity)
+                # Synthesise a response based on what we have in the database.
+                commit_oids = [self.commit_sha1]
+                tip = {"sha1": self.commit_sha1, "synthetic": True}
+                optional_fields = (
+                    "author", "author_date", "committer", "committer_date",
+                    "commit_message")
+                for field in optional_fields:
+                    if getattr(self, field) is not None:
+                        tip[field] = getattr(self, field)
+                parsed_commits = {self.commit_sha1: tip}
         commits = []
-        for commit in log:
-            if "sha1" not in commit:
-                continue
-            parsed_commit = parsed_commits[commit["sha1"]]
+        for commit_oid in commit_oids:
+            parsed_commit = parsed_commits[commit_oid]
             author_date = parsed_commit.get("author_date")
             if start_date is not None:
                 if author_date is None or author_date < start_date:
@@ -390,8 +414,11 @@
             commits.append(parsed_commit)
         return commits
 
-    def getLatestCommits(self, quantity=10, extended_details=False, user=None):
-        commits = self.getCommits(self.commit_sha1, limit=quantity)
+    def getLatestCommits(self, quantity=10, extended_details=False, user=None,
+                         logger=None):
+        commits = self.getCommits(
+            self.commit_sha1, limit=quantity, handle_timeout=True,
+            logger=logger)
         if extended_details:
             # XXX cjwatson 2016-05-09: Add support for linked bugtasks once
             # those are supported for Git.

=== modified file 'lib/lp/code/templates/git-macros.pt'
--- lib/lp/code/templates/git-macros.pt	2018-08-24 16:52:27 +0000
+++ lib/lp/code/templates/git-macros.pt	2018-11-29 12:18:57 +0000
@@ -135,6 +135,11 @@
       </tal:diff-expander>
     </tal:ajax-revision-diffs>
   </dl>
+  <tal:synthetic
+      condition="python: any(commit_info.get('synthetic')
+                             for commit_info in commit_infos)">
+    <div>Some recent commit information could not be fetched.</div>
+  </tal:synthetic>
 
 </metal:ref-commits>