Add timing for repo snapshots - debug frontend TO

We're getting timeouts when trying to scan guardian/frontend.
guardian · Jan 26, 2023 · 8ff1519 · 8ff1519
1 parent a8860e7
commit 8ff1519
Show file tree

Hide file tree

Showing 2 changed files with 29 additions and 13 deletions.
diff --git a/app/lib/RepoSnapshot.scala b/app/lib/RepoSnapshot.scala
@@ -57,29 +57,45 @@ object RepoSnapshot {
     implicit val github: GitHub = bot.github
 
     def log(message: String)(implicit repo: Repo): Unit = logger.info(s"${repo.full_name} - $message")
+    def logAround[T](desc: String)(thunk: => Future[T])(implicit repo: Repo): Future[T] = {
+      val start = System.currentTimeMillis()
+      thunk.onComplete { attempt =>
+        val elapsedMs = System.currentTimeMillis() - start
+        log(s"'$desc' $elapsedMs ms : success=${attempt.isSuccess}")
+      }
+      thunk
+    }
 
     def isMergedToMain(pr: PullRequest)(implicit repo: Repo): Boolean =
       pr.merged_at.isDefined && pr.base.ref == repo.default_branch
 
     def snapshot(repoId: RepoId): Future[RepoSnapshot] = for {
       githubRepo <- github.getRepo(repoId)
-      mergedPullRequests <- mergedPullRequestsFor(githubRepo)
-      hooksF = snapshotHooks(githubRepo)
-      gitRepoF = fetchLatestCopyOfGitRepo(githubRepo)
-      gitRepo <- gitRepoF
-      hooks <- hooksF
-    } yield RepoSnapshot(
-      RepoLevelDetails(githubRepo, gitRepo, hooks),
-      mergedPullRequests, checkpointSnapshoter
-    )
+      repoSnapshot <- snapshot(githubRepo)
+    } yield repoSnapshot
+
+    def snapshot(implicit githubRepo: Repo): Future[RepoSnapshot] = {
+      val mergedPullRequestsF = logAround("fetch PRs")(fetchMergedPullRequests())
+      val hooksF = logAround("fetch repo hooks")(fetchRepoHooks())
+      val gitRepoF = logAround("fetch git repo")(fetchLatestCopyOfGitRepo())
+
+      for {
+        mergedPullRequests <- mergedPullRequestsF
+        gitRepo <- gitRepoF
+        hooks <- hooksF
+      } yield RepoSnapshot(
+        RepoLevelDetails(githubRepo, gitRepo, hooks),
+        mergedPullRequests, checkpointSnapshoter
+      )
+    }
 
     def prSnapshot(prNumber: Int)(implicit repo: Repo): Future[PRSnapshot] = for {
       prResponse <- repo.pullRequests.get(prNumber)
       pr = prResponse.result
       labelsResponse <- pr.labels.list().all()
     } yield PRSnapshot(pr, labelsResponse)
 
-    def mergedPullRequestsFor(implicit repo: Repo): Future[Seq[PRSnapshot]] = {
+    def fetchMergedPullRequests()(implicit repo: Repo): Future[Seq[PRSnapshot]] = {
       val now = ZonedDateTime.now()
       val timeThresholdForScan = now.minus(WorthyOfScanWindow)
 
@@ -96,7 +112,7 @@ object RepoSnapshot {
       }) andThen { case cprs => log(s"Merged Pull Requests fetched: ${cprs.map(_.map(_.pr.number).sorted.reverse)}") }
     }
 
-    private def fetchLatestCopyOfGitRepo(implicit githubRepo: Repo): Future[Repository] = {
+    private def fetchLatestCopyOfGitRepo()(implicit githubRepo: Repo): Future[Repository] = {
       Future {
         val repoId = githubRepo.repoId
         RepoUtil.getGitRepo(
@@ -106,7 +122,7 @@ object RepoSnapshot {
       } andThen { case r => log(s"Git Repo ref count: ${r.map(_.getRefDatabase.getRefs.size)}") }
     }
 
-    private def snapshotHooks(implicit githubRepo: Repo) = if (githubRepo.permissions.exists(_.admin)) githubRepo.hooks.list().map(_.flatMap(_.config.get("url").map(Url.parse))).all() else {
+    private def fetchRepoHooks()(implicit githubRepo: Repo) = if (githubRepo.permissions.exists(_.admin)) githubRepo.hooks.list().map(_.flatMap(_.config.get("url").map(Url.parse))).all() else {
       log(s"No admin rights to check hooks")
       Future.successful(Seq.empty)
     }

diff --git a/app/lib/RepoUtil.scala b/app/lib/RepoUtil.scala
@@ -34,7 +34,7 @@ object RepoUtil extends Logging {
   def getGitRepo(dataDirectory: File, uri: String, credentials: Option[CredentialsProvider] = None): Repository = {
 
     def invoke[C <: GitCommand[_], R](command: TransportCommand[C, R]): R = {
-      command.setTimeout(5)
+      command.setTimeout(15)
       credentials.foreach(command.setCredentialsProvider)
       command.call()
     }