Merge branch 'stable-3.0' into stable-3.1

* stable-3.0:
  Add metric monitoring Java deadlocks
  Fix wrong status returned when auth backend couldn't be reached
  Add debug logs for copying approvals to new patch sets
  Revert "ApprovalCopier: Add debug logging of logic in canCopy"
  ChangeKindCacheImpl: Add debug logging of detected change kind
  ApprovalCopier: Add debug logging of logic in canCopy

Change-Id: I3c939a638e588ed0c3df79916b077445c5da5472

5 files changed, 198 insertions, 11 deletions

diff --git a/Documentation/metrics.txt b/Documentation/metrics.txt
index b2f2233219..2545b5d931 100644
--- a/Documentation/metrics.txt
+++ b/Documentation/metrics.txt
@@ -54,6 +54,8 @@ objects needing finalization.
 * `proc/jvm/thread/num_daemon_live`: Current live daemon threads count.
 * `proc/jvm/thread/num_peak_live`: Peak live thread count since the Java virtual machine started or peak was reset.
 * `proc/jvm/thread/num_total_started`: Total number of threads created and also started since the Java virtual machine started.
+* `proc/jvm/thread/num_deadlocked_threads`: Number of threads that are deadlocked waiting for object monitors or ownable synchronizers.
+   If deadlocks waiting for ownable synchronizers can be monitored depends on the capabilities of the used JVM.
 
 === Caches
 
diff --git a/java/com/google/gerrit/httpd/ProjectBasicAuthFilter.java b/java/com/google/gerrit/httpd/ProjectBasicAuthFilter.java
index 88a3f0ab0c..e75d8feada 100644
--- a/java/com/google/gerrit/httpd/ProjectBasicAuthFilter.java
+++ b/java/com/google/gerrit/httpd/ProjectBasicAuthFilter.java
@@ -15,6 +15,7 @@
 package com.google.gerrit.httpd;
 
 import static java.nio.charset.StandardCharsets.UTF_8;
+import static javax.servlet.http.HttpServletResponse.SC_SERVICE_UNAVAILABLE;
 import static javax.servlet.http.HttpServletResponse.SC_UNAUTHORIZED;
 
 import com.google.common.base.MoreObjects;
@@ -32,6 +33,7 @@ import com.google.gerrit.server.account.AuthRequest;
 import com.google.gerrit.server.account.AuthResult;
 import com.google.gerrit.server.account.AuthenticationFailedException;
 import com.google.gerrit.server.account.externalids.PasswordVerifier;
+import com.google.gerrit.server.auth.AuthenticationUnavailableException;
 import com.google.gerrit.server.auth.NoSuchUserException;
 import com.google.gerrit.server.config.AuthConfig;
 import com.google.inject.Inject;
@@ -170,6 +172,10 @@ class ProjectBasicAuthFilter implements Filter {
       logger.atWarning().log(authenticationFailedMsg(username, req) + ": %s", e.getMessage());
       rsp.sendError(SC_UNAUTHORIZED);
       return false;
+    } catch (AuthenticationUnavailableException e) {
+      logger.atSevere().withCause(e).log("could not reach authentication backend");
+      rsp.sendError(SC_SERVICE_UNAVAILABLE);
+      return false;
     } catch (AccountException e) {
       logger.atWarning().withCause(e).log(authenticationFailedMsg(username, req));
       rsp.sendError(SC_UNAUTHORIZED);
diff --git a/java/com/google/gerrit/metrics/proc/ProcMetricModule.java b/java/com/google/gerrit/metrics/proc/ProcMetricModule.java
index fced1783c6..20ac8fa908 100644
--- a/java/com/google/gerrit/metrics/proc/ProcMetricModule.java
+++ b/java/com/google/gerrit/metrics/proc/ProcMetricModule.java
@@ -234,5 +234,36 @@ public class ProcMetricModule extends MetricModule {
             .setGauge()
             .setUnit("threads"),
         thread::getTotalStartedThreadCount);
+    if (thread.isSynchronizerUsageSupported()) {
+      metrics.newCallbackMetric(
+          "proc/jvm/thread/num_deadlocked_threads",
+          Integer.class,
+          new Description(
+                  "number of threads that are deadlocked waiting for object monitors or ownable synchronizers")
+              .setGauge()
+              .setUnit("threads"),
+          () -> {
+            long[] deadlocked = thread.findDeadlockedThreads();
+            if (deadlocked == null) {
+              return 0;
+            }
+            return deadlocked.length;
+          });
+    } else {
+      metrics.newCallbackMetric(
+          "proc/jvm/thread/num_deadlocked_threads",
+          Integer.class,
+          new Description(
+                  "number of threads that are deadlocked waiting to acquire object monitors")
+              .setGauge()
+              .setUnit("threads"),
+          () -> {
+            long[] deadlocked = thread.findMonitorDeadlockedThreads();
+            if (deadlocked == null) {
+              return 0;
+            }
+            return deadlocked.length;
+          });
+    }
   }
 }
diff --git a/java/com/google/gerrit/server/ApprovalInference.java b/java/com/google/gerrit/server/ApprovalInference.java
index 44b0529dde..566a32bf56 100644
--- a/java/com/google/gerrit/server/ApprovalInference.java
+++ b/java/com/google/gerrit/server/ApprovalInference.java
@@ -20,6 +20,7 @@ import static com.google.common.base.Preconditions.checkState;
 import com.google.common.collect.HashBasedTable;
 import com.google.common.collect.ImmutableList;
 import com.google.common.collect.Table;
+import com.google.common.flogger.FluentLogger;
 import com.google.gerrit.common.Nullable;
 import com.google.gerrit.common.data.LabelType;
 import com.google.gerrit.entities.Account;
@@ -54,6 +55,8 @@ import org.eclipse.jgit.revwalk.RevWalk;
  */
 @Singleton
 public class ApprovalInference {
+  private static final FluentLogger logger = FluentLogger.forEnclosingClass();
+
   private final ProjectCache projectCache;
   private final ChangeKindCache changeKindCache;
   private final LabelNormalizer labelNormalizer;
@@ -95,27 +98,163 @@ public class ApprovalInference {
     checkArgument(n != psId.get());
     LabelType type = project.getLabelTypes().byLabel(psa.labelId());
     if (type == null) {
+      logger.atFine().log(
+          "approval %d on label %s of patch set %d of change %d cannot be copied"
+              + " to patch set %d because the label no longer exists on project %s",
+          psa.value(),
+          psa.label(),
+          n,
+          psa.key().patchSetId().changeId().get(),
+          psId.get(),
+          project.getName());
       return false;
-    } else if ((type.isCopyMinScore() && type.isMaxNegative(psa))
-        || (type.isCopyMaxScore() && type.isMaxPositive(psa))) {
+    } else if (type.isCopyMinScore() && type.isMaxNegative(psa)) {
+      logger.atFine().log(
+          "veto approval %s on label %s of patch set %d of change %d can be copied"
+              + " to patch set %d because the label has set copyMinScore = true on project %s",
+          psa.value(),
+          psa.label(),
+          n,
+          psa.key().patchSetId().changeId().get(),
+          psId.get(),
+          project.getName());
+      return true;
+    } else if (type.isCopyMaxScore() && type.isMaxPositive(psa)) {
+      logger.atFine().log(
+          "max approval %s on label %s of patch set %d of change %d can be copied"
+              + " to patch set %d because the label has set copyMaxScore = true on project %s",
+          psa.value(),
+          psa.label(),
+          n,
+          psa.key().patchSetId().changeId().get(),
+          psId.get(),
+          project.getName());
       return true;
     } else if (type.isCopyAnyScore()) {
+      logger.atFine().log(
+          "approval %d on label %s of patch set %d of change %d can be copied"
+              + " to patch set %d because the label has set copyAnyScore = true on project %s",
+          psa.value(),
+          psa.label(),
+          n,
+          psa.key().patchSetId().changeId().get(),
+          psId.get(),
+          project.getName());
       return true;
     }
     switch (kind) {
       case MERGE_FIRST_PARENT_UPDATE:
-        return type.isCopyAllScoresOnMergeFirstParentUpdate();
+        if (type.isCopyAllScoresOnMergeFirstParentUpdate()) {
+          logger.atFine().log(
+              "approval %d on label %s of patch set %d of change %d can be copied"
+                  + " to patch set %d because change kind is %s and the label has set"
+                  + " copyAllScoresOnMergeFirstParentUpdate = true on project %s",
+              psa.value(),
+              psa.label(),
+              n,
+              psa.key().patchSetId().changeId().get(),
+              psId.get(),
+              kind,
+              project.getName());
+          return true;
+        }
+        return false;
       case NO_CODE_CHANGE:
-        return type.isCopyAllScoresIfNoCodeChange();
+        if (type.isCopyAllScoresIfNoCodeChange()) {
+          logger.atFine().log(
+              "approval %d on label %s of patch set %d of change %d can be copied"
+                  + " to patch set %d because change kind is %s and the label has set"
+                  + " copyAllScoresIfNoCodeChange = true on project %s",
+              psa.value(),
+              psa.label(),
+              n,
+              psa.key().patchSetId().changeId().get(),
+              psId.get(),
+              kind,
+              project.getName());
+          return true;
+        }
+        return false;
       case TRIVIAL_REBASE:
-        return type.isCopyAllScoresOnTrivialRebase();
+        if (type.isCopyAllScoresOnTrivialRebase()) {
+          logger.atFine().log(
+              "approval %d on label %s of patch set %d of change %d can be copied"
+                  + " to patch set %d because change kind is %s and the label has set"
+                  + " copyAllScoresOnTrivialRebase = true on project %s",
+              psa.value(),
+              psa.label(),
+              n,
+              psa.key().patchSetId().changeId().get(),
+              psId.get(),
+              kind,
+              project.getName());
+          return true;
+        }
+        return false;
       case NO_CHANGE:
-        return type.isCopyAllScoresIfNoChange()
-            || type.isCopyAllScoresOnTrivialRebase()
-            || type.isCopyAllScoresOnMergeFirstParentUpdate()
-            || type.isCopyAllScoresIfNoCodeChange();
+        if (type.isCopyAllScoresIfNoChange()) {
+          logger.atFine().log(
+              "approval %d on label %s of patch set %d of change %d can be copied"
+                  + " to patch set %d because change kind is %s and the label has set"
+                  + " copyAllScoresIfNoCodeChange = true on project %s",
+              psa.value(),
+              psa.label(),
+              n,
+              psa.key().patchSetId().changeId().get(),
+              psId.get(),
+              kind,
+              project.getName());
+          return true;
+        }
+        if (type.isCopyAllScoresOnTrivialRebase()) {
+          logger.atFine().log(
+              "approval %d on label %s of patch set %d of change %d can be copied"
+                  + " to patch set %d because change kind is %s and the label has set"
+                  + " copyAllScoresOnTrivialRebase = true on project %s",
+              psa.value(),
+              psa.label(),
+              n,
+              psa.key().patchSetId().changeId().get(),
+              psId.get(),
+              kind,
+              project.getName());
+          return true;
+        }
+        if (type.isCopyAllScoresOnMergeFirstParentUpdate()) {
+          logger.atFine().log(
+              "approval %d on label %s of patch set %d of change %d can be copied"
+                  + " to patch set %d because change kind is %s and the label has set"
+                  + " copyAllScoresOnMergeFirstParentUpdate = true on project %s",
+              psa.value(),
+              psa.label(),
+              n,
+              psa.key().patchSetId().changeId().get(),
+              psId.get(),
+              kind,
+              project.getName());
+          return true;
+        }
+        if (type.isCopyAllScoresIfNoCodeChange()) {
+          logger.atFine().log(
+              "approval %d on label %s of patch set %d of change %d can be copied"
+                  + " to patch set %d because change kind is %s and the label has set"
+                  + " copyAllScoresIfNoCodeChange = true on project %s",
+              psa.value(),
+              psa.label(),
+              n,
+              psa.key().patchSetId().changeId().get(),
+              psId.get(),
+              kind,
+              project.getName());
+          return true;
+        }
+        return false;
       case REWORK:
       default:
+        logger.atFine().log(
+            "approval %d on label %s of patch set %d of change %d cannot be copied"
+                + " to patch set %d because change kind is %s",
+            psa.value(), psa.label(), n, psa.key().patchSetId().changeId().get(), psId.get(), kind);
         return false;
     }
   }
@@ -177,6 +316,9 @@ public class ApprovalInference {
             repoConfig,
             priorPatchSet.getValue().commitId(),
             ps.commitId());
+    logger.atFine().log(
+        "change kind for patch set %d of change %d against prior patch set %s is %s",
+        ps.id().get(), ps.id().changeId().get(), priorPatchSet.getValue().id().changeId(), kind);
     for (PatchSetApproval psa : priorApprovals) {
       if (resultByUser.contains(psa.label(), psa.accountId())) {
         continue;
diff --git a/java/com/google/gerrit/server/change/ChangeKindCacheImpl.java b/java/com/google/gerrit/server/change/ChangeKindCacheImpl.java
index 682b46c10c..1e149548db 100644
--- a/java/com/google/gerrit/server/change/ChangeKindCacheImpl.java
+++ b/java/com/google/gerrit/server/change/ChangeKindCacheImpl.java
@@ -344,10 +344,12 @@ public class ChangeKindCacheImpl implements ChangeKindCache {
       ObjectId next) {
     try {
       Key key = Key.create(prior, next, useRecursiveMerge);
-      return cache.get(key, new Loader(key, repoManager, project, rw, repoConfig));
+      ChangeKind kind = cache.get(key, new Loader(key, repoManager, project, rw, repoConfig));
+      logger.atFine().log("Change kind of new patch set %s in %s: %s", next.name(), project, kind);
+      return kind;
     } catch (ExecutionException e) {
       logger.atWarning().withCause(e).log(
-          "Cannot check trivial rebase of new patch set %s in %s", next.name(), project);
+          "Cannot check change kind of new patch set %s in %s", next.name(), project);
       return ChangeKind.REWORK;
     }
   }
@@ -400,6 +402,8 @@ public class ChangeKindCacheImpl implements ChangeKindCache {
             patch.number(), change.getId());
       }
     }
+    logger.atFine().log(
+        "Change kind for patchSet %s of change %s: %s", patch.number(), change.getId(), kind);
     return kind;
   }
 
@@ -426,6 +430,8 @@ public class ChangeKindCacheImpl implements ChangeKindCache {
             patch.number(), change.getChangeId());
       }
     }
+    logger.atFine().log(
+        "Change kind for patchSet %s of change %s: %s", patch.number(), change.getChangeId(), kind);
     return kind;
   }
 }