CheckAccess: Return ACL debug logs

A very common support issue is helping users to find out which
permissions they are missing in order to perform a certain operation.

To let host admin investigate such issues the CheckAccess REST endpoint
has been added, however often it doesn't provide enough information for
host admins to understand why a permission is denied or allowed.

If a request is traced detailed information about which ACL rule
denied/granted the permission is available in the trace, but it requires
a server admin to look at the trace.

This change makes the logs that are relevant for ACLs available to
callers of the CheckAccess REST endpoint. It's okay to return these logs
from this REST endpoint since it requires the global Check Access
capability which should only be granted to trusted users (aka host
admins).

To make ACL logs available to the CheckAccess REST endpoint they are
collected in memory in the LoggingContext, similar to how the
LoggingContext stores performance logs. After triggering permission
checks, the CheckAccess REST endpoint can retrieve the ACL logs from the
LoggingContext and include them into the response to the client.

The collection of ACL log records is only enabled for the CheckAccess
REST endpoint, and is disabled for any other REST endpoint.

I tried to add a new method to the fluent logging API that allows to
send a log into the server logs and into the ACL logs at the same time,
e.g. logger.atFine().includeIntoAclLog().log(...) but it turned out that
this is not possible with Flogger (we can add new methods to the logging
API, but we have no access to the logged message to send it to the
LoggingContext). Anyway it turned out that for the permission checks the
message that we want to log in the server logs and the message that we
want to include into the ACL logs is slightly different, so that we
wouldn't have benefited much from such a new method in the logging API.

Change-Id: If82eb586272adecda445949989a314614cdd1072
Signed-off-by: Edwin Kempin <ekempin@google.com>

Documentation/rest-api-projects.txt

@@ -3393,6 +3393,8 @@ The `AccessCheckInfo` entity is the result of an access check.
 |`status`                    ||The HTTP status code for the access.
 200 means success and 403 means denied.
 |`message`                   |optional|A clarifying message if `status` is not 200.
+|`debug_logs`                |optional|
+Debug logs that may help to understand why a permission is denied or allowed.
 |=========================================
 
 [[auto_closeable_changes_check_input]]

java/com/google/gerrit/extensions/api/config/AccessCheckInfo.java

@@ -14,10 +14,15 @@
 
 package com.google.gerrit.extensions.api.config;
 
+import java.util.List;
+
 public class AccessCheckInfo {
   public String message;
   // HTTP status code
   public int status;
 
+  /** Debug logs that may help to understand why a permission is denied or allowed. */
+  public List<String> debugLogs;
+
   // for future extension, we may add inputs / results for bulk checks.
 }

java/com/google/gerrit/server/logging/LoggingContext.java

@@ -42,11 +42,12 @@ public class LoggingContext extends com.google.common.flogger.backend.system.Log
   private static final ThreadLocal<MutableTags> tags = new ThreadLocal<>();
   private static final ThreadLocal<Boolean> forceLogging = new ThreadLocal<>();
   private static final ThreadLocal<Boolean> performanceLogging = new ThreadLocal<>();
+  private static final ThreadLocal<Boolean> aclLogging = new ThreadLocal<>();
 
   /**
-   * When copying the logging context to a new thread we need to ensure that the performance log
+   * When copying the logging context to a new thread we need to ensure that the mutable log records
-   * records that are added in the new thread are added to the same {@link
+   * (performance logs and ACL logs) that are added in the new thread are added to the same multable
-   * MutablePerformanceLogRecords} instance (see {@link LoggingContextAwareRunnable} and {@link
+   * log records instance (see {@link LoggingContextAwareRunnable} and {@link
    * LoggingContextAwareCallable}). This is important since performance log records are processed
    * only at the end of the request and performance log records that are created in another thread
    * should not get lost.
@@ -54,6 +55,8 @@ public class LoggingContext extends com.google.common.flogger.backend.system.Log
   private static final ThreadLocal<MutablePerformanceLogRecords> performanceLogRecords =
       new ThreadLocal<>();
 
+  private static final ThreadLocal<MutableAclLogRecords> aclLogRecords = new ThreadLocal<>();
+
   private LoggingContext() {}
 
   /** This method is expected to be called via reflection (and might otherwise be unused). */
@@ -67,7 +70,9 @@ public class LoggingContext extends com.google.common.flogger.backend.system.Log
     }
 
     return new LoggingContextAwareRunnable(
-        runnable, getInstance().getMutablePerformanceLogRecords());
+        runnable,
+        getInstance().getMutablePerformanceLogRecords(),
+        getInstance().getMutableAclRecords());
   }
 
   public static <T> Callable<T> copy(Callable<T> callable) {
@@ -76,14 +81,18 @@ public class LoggingContext extends com.google.common.flogger.backend.system.Log
     }
 
     return new LoggingContextAwareCallable<>(
-        callable, getInstance().getMutablePerformanceLogRecords());
+        callable,
+        getInstance().getMutablePerformanceLogRecords(),
+        getInstance().getMutableAclRecords());
   }
 
   public boolean isEmpty() {
     return tags.get() == null
         && forceLogging.get() == null
         && performanceLogging.get() == null
-        && performanceLogRecords.get() == null;
+        && performanceLogRecords.get() == null
+        && aclLogging.get() == null
+        && aclLogRecords.get() == null;
   }
 
   public void clear() {
@@ -91,6 +100,8 @@ public class LoggingContext extends com.google.common.flogger.backend.system.Log
     forceLogging.remove();
     performanceLogging.remove();
     performanceLogRecords.remove();
+    aclLogging.remove();
+    aclLogRecords.remove();
   }
 
   @Override
@@ -250,6 +261,101 @@ public class LoggingContext extends com.google.common.flogger.backend.system.Log
     return records;
   }
 
+  public boolean isAclLogging() {
+    Boolean isAclLogging = aclLogging.get();
+    return isAclLogging != null ? isAclLogging : false;
+  }
+
+  /**
+   * Enables ACL logging.
+   *
+   * <p>It's important to enable ACL logging only in a context that ensures to consume the captured
+   * ACL log records. Otherwise captured ACL log records might leak into other requests that are
+   * executed by the same thread (if a thread pool is used to process requests).
+   *
+   * @param enable whether ACL logging should be enabled.
+   * @return whether ACL logging was be enabled before invoking this method (old value).
+   */
+  boolean aclLogging(boolean enable) {
+    Boolean oldValue = aclLogging.get();
+    if (enable) {
+      aclLogging.set(true);
+    } else {
+      aclLogging.remove();
+    }
+    return oldValue != null ? oldValue : false;
+  }
+
+  /**
+   * Adds an ACL log record.
+   *
+   * @param aclLogRecord ACL log record
+   */
+  public void addAclLogRecord(String aclLogRecord) {
+    if (!isAclLogging()) {
+      return;
+    }
+
+    getMutableAclRecords().add(aclLogRecord);
+  }
+
+  ImmutableList<String> getAclLogRecords() {
+    MutableAclLogRecords records = aclLogRecords.get();
+    if (records != null) {
+      return records.list();
+    }
+    return ImmutableList.of();
+  }
+
+  void clearAclLogEntries() {
+    aclLogRecords.remove();
+  }
+
+  /**
+   * Set the ACL log records in this logging context. Existing log records are overwritten.
+   *
+   * <p>This method makes a defensive copy of the passed in list.
+   *
+   * @param newAclLogRecords ACL log records that should be set
+   */
+  void setAclLogRecords(List<String> newAclLogRecords) {
+    if (newAclLogRecords.isEmpty()) {
+      aclLogRecords.remove();
+      return;
+    }
+
+    getMutableAclRecords().set(newAclLogRecords);
+  }
+
+  /**
+   * Sets a {@link MutableAclLogRecords} instance for storing ACL log records.
+   *
+   * <p><strong>Attention:</strong> The passed in {@link MutableAclLogRecords} instance is directly
+   * stored in the logging context.
+   *
+   * <p>This method is intended to be only used when the logging context is copied to a new thread
+   * to ensure that the ACL log records that are added in the new thread are added to the same
+   * {@link MutableAclLogRecords} instance (see {@link LoggingContextAwareRunnable} and {@link
+   * LoggingContextAwareCallable}). This is important since ACL log records are processed only at
+   * the end of the request and ACL log records that are created in another thread should not get
+   * lost.
+   *
+   * @param mutableAclLogRecords the {@link MutableAclLogRecords} instance in which ACL log records
+   *     should be stored
+   */
+  void setMutableAclLogRecords(MutableAclLogRecords mutableAclLogRecords) {
+    aclLogRecords.set(requireNonNull(mutableAclLogRecords));
+  }
+
+  private MutableAclLogRecords getMutableAclRecords() {
+    MutableAclLogRecords records = aclLogRecords.get();
+    if (records == null) {
+      records = new MutableAclLogRecords();
+      aclLogRecords.set(records);
+    }
+    return records;
+  }
+
   @Override
   public String toString() {
     return MoreObjects.toStringHelper(this)
@@ -257,6 +363,8 @@ public class LoggingContext extends com.google.common.flogger.backend.system.Log
         .add("forceLogging", forceLogging.get())
         .add("performanceLogging", performanceLogging.get())
         .add("performanceLogRecords", performanceLogRecords.get())
+        .add("aclLogging", aclLogging.get())
+        .add("aclLogRecords", aclLogRecords.get())
         .toString();
   }
 }

java/com/google/gerrit/server/logging/LoggingContextAwareCallable.java

@@ -40,6 +40,8 @@ class LoggingContextAwareCallable<T> implements Callable<T> {
   private final boolean forceLogging;
   private final boolean performanceLogging;
   private final MutablePerformanceLogRecords mutablePerformanceLogRecords;
+  private final boolean aclLogging;
+  private final MutableAclLogRecords mutableAclLogRecords;
 
   /**
    * Creates a LoggingContextAwareCallable that wraps the given {@link Callable}.
@@ -47,15 +49,21 @@ class LoggingContextAwareCallable<T> implements Callable<T> {
    * @param callable Callable that should be wrapped.
    * @param mutablePerformanceLogRecords instance of {@link MutablePerformanceLogRecords} to which
    *     performance log records that are created from the runnable are added
+   * @param mutableAclLogRecords instance of {@link MutableAclLogRecords} to which ACL log records
+   *     that are created from the runnable are added
    */
   LoggingContextAwareCallable(
-      Callable<T> callable, MutablePerformanceLogRecords mutablePerformanceLogRecords) {
+      Callable<T> callable,
+      MutablePerformanceLogRecords mutablePerformanceLogRecords,
+      MutableAclLogRecords mutableAclLogRecords) {
     this.callable = callable;
     this.callingThread = Thread.currentThread();
     this.tags = LoggingContext.getInstance().getTagsAsMap();
     this.forceLogging = LoggingContext.getInstance().isLoggingForced();
     this.performanceLogging = LoggingContext.getInstance().isPerformanceLogging();
     this.mutablePerformanceLogRecords = mutablePerformanceLogRecords;
+    this.aclLogging = LoggingContext.getInstance().isAclLogging();
+    this.mutableAclLogRecords = mutableAclLogRecords;
   }
 
   @Override
@@ -76,6 +84,8 @@ class LoggingContextAwareCallable<T> implements Callable<T> {
     loggingCtx.forceLogging(forceLogging);
     loggingCtx.performanceLogging(performanceLogging);
     loggingCtx.setMutablePerformanceLogRecords(mutablePerformanceLogRecords);
+    loggingCtx.aclLogging(aclLogging);
+    loggingCtx.setMutableAclLogRecords(mutableAclLogRecords);
     try {
       return callable.call();
     } finally {

java/com/google/gerrit/server/logging/LoggingContextAwareRunnable.java

@@ -58,6 +58,8 @@ public class LoggingContextAwareRunnable implements Runnable {
   private final boolean forceLogging;
   private final boolean performanceLogging;
   private final MutablePerformanceLogRecords mutablePerformanceLogRecords;
+  private final boolean aclLogging;
+  private final MutableAclLogRecords mutableAclLogRecords;
 
   /**
    * Creates a LoggingContextAwareRunnable that wraps the given {@link Runnable}.
@@ -65,15 +67,21 @@ public class LoggingContextAwareRunnable implements Runnable {
    * @param runnable Runnable that should be wrapped.
    * @param mutablePerformanceLogRecords instance of {@link MutablePerformanceLogRecords} to which
    *     performance log records that are created from the runnable are added
+   * @param mutableAclLogRecords instance of {@link MutableAclLogRecords} to which ACL log records
+   *     that are created from the runnable are added
    */
   LoggingContextAwareRunnable(
-      Runnable runnable, MutablePerformanceLogRecords mutablePerformanceLogRecords) {
+      Runnable runnable,
+      MutablePerformanceLogRecords mutablePerformanceLogRecords,
+      MutableAclLogRecords mutableAclLogRecords) {
     this.runnable = runnable;
     this.callingThread = Thread.currentThread();
     this.tags = LoggingContext.getInstance().getTagsAsMap();
     this.forceLogging = LoggingContext.getInstance().isLoggingForced();
     this.performanceLogging = LoggingContext.getInstance().isPerformanceLogging();
     this.mutablePerformanceLogRecords = mutablePerformanceLogRecords;
+    this.aclLogging = LoggingContext.getInstance().isAclLogging();
+    this.mutableAclLogRecords = mutableAclLogRecords;
   }
 
   public Runnable unwrap() {
@@ -99,6 +107,8 @@ public class LoggingContextAwareRunnable implements Runnable {
     loggingCtx.forceLogging(forceLogging);
     loggingCtx.performanceLogging(performanceLogging);
     loggingCtx.setMutablePerformanceLogRecords(mutablePerformanceLogRecords);
+    loggingCtx.aclLogging(aclLogging);
+    loggingCtx.setMutableAclLogRecords(mutableAclLogRecords);
     try {
       runnable.run();
     } finally {

java/com/google/gerrit/server/logging/MutableAclLogRecords.java

@@ -0,0 +1,52 @@
+// Copyright (C) 2020 The Android Open Source Project
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package com.google.gerrit.server.logging;
+
+import com.google.common.base.MoreObjects;
+import com.google.common.collect.ImmutableList;
+import java.util.ArrayList;
+import java.util.List;
+
+/**
+ * Thread-safe store for ACL log records.
+ *
+ * <p>This class is intended to keep track of user ACL records in {@link LoggingContext}. It needs
+ * to be thread-safe because it gets shared between threads when the logging context is copied to
+ * another thread (see {@link LoggingContextAwareRunnable} and {@link LoggingContextAwareCallable}.
+ * In this case the logging contexts of both threads share the same instance of this class. This is
+ * important since ACL log records are processed only at the end of a request and user ACL records
+ * that are created in another thread should not get lost.
+ */
+public class MutableAclLogRecords {
+  private final ArrayList<String> aclLogRecords = new ArrayList<>();
+
+  public synchronized void add(String record) {
+    aclLogRecords.add(record);
+  }
+
+  public synchronized void set(List<String> records) {
+    aclLogRecords.clear();
+    aclLogRecords.addAll(records);
+  }
+
+  public synchronized ImmutableList<String> list() {
+    return ImmutableList.copyOf(aclLogRecords);
+  }
+
+  @Override
+  public String toString() {
+    return MoreObjects.toStringHelper(this).add("aclLogRecords", aclLogRecords).toString();
+  }
+}

java/com/google/gerrit/server/logging/TraceContext.java

@@ -19,6 +19,7 @@ import static java.util.Objects.requireNonNull;
 import com.google.common.base.Stopwatch;
 import com.google.common.base.Strings;
 import com.google.common.collect.HashBasedTable;
+import com.google.common.collect.ImmutableList;
 import com.google.common.collect.ImmutableMap;
 import com.google.common.collect.Table;
 import com.google.common.flogger.FluentLogger;
@@ -222,9 +223,17 @@ public class TraceContext implements AutoCloseable {
   // Table<TAG_NAME, TAG_VALUE, REMOVE_ON_CLOSE>
   private final Table<String, String, Boolean> tags = HashBasedTable.create();
 
-  private boolean stopForceLoggingOnClose;
+  private final boolean oldAclLogging;
+  private final ImmutableList<String> oldAclLogRecords;
 
-  private TraceContext() {}
+  private boolean stopForceLoggingOnClose;
+  private boolean stopAclLoggingOnClose;
+
+  private TraceContext() {
+    // Just in case remember the old state and reset ACL log entries.
+    this.oldAclLogging = LoggingContext.getInstance().isAclLogging();
+    this.oldAclLogRecords = LoggingContext.getInstance().getAclLogRecords();
+  }
 
   public TraceContext addTag(RequestId.Type requestId, Object tagValue) {
     return addTag(requireNonNull(requestId, "request ID is required").name(), tagValue);
@@ -265,6 +274,23 @@ public class TraceContext implements AutoCloseable {
         .findFirst();
   }
 
+  public TraceContext enableAclLogging() {
+    if (stopAclLoggingOnClose) {
+      return this;
+    }
+
+    stopAclLoggingOnClose = !LoggingContext.getInstance().aclLogging(true);
+    return this;
+  }
+
+  public boolean isAclLoggingEnabled() {
+    return LoggingContext.getInstance().isAclLogging();
+  }
+
+  public ImmutableList<String> getAclLogRecords() {
+    return LoggingContext.getInstance().getAclLogRecords();
+  }
+
   @Override
   public void close() {
     for (Table.Cell<String, String, Boolean> cell : tags.cellSet()) {
@@ -275,5 +301,10 @@ public class TraceContext implements AutoCloseable {
     if (stopForceLoggingOnClose) {
       LoggingContext.getInstance().forceLogging(false);
     }
+
+    if (stopAclLoggingOnClose) {
+      LoggingContext.getInstance().aclLogging(oldAclLogging);
+      LoggingContext.getInstance().setAclLogRecords(oldAclLogRecords);
+    }
   }
 }

java/com/google/gerrit/server/permissions/RefControl.java

@@ -29,6 +29,7 @@ import com.google.gerrit.extensions.conditions.BooleanCondition;
 import com.google.gerrit.extensions.restapi.AuthException;
 import com.google.gerrit.server.CurrentUser;
 import com.google.gerrit.server.logging.CallerFinder;
+import com.google.gerrit.server.logging.LoggingContext;
 import com.google.gerrit.server.notedb.ChangeNotes;
 import com.google.gerrit.server.permissions.PermissionBackend.ForChange;
 import com.google.gerrit.server.permissions.PermissionBackend.ForRef;
@@ -397,40 +398,52 @@ class RefControl {
   /** True if the user has this permission. */
   private boolean canPerform(String permissionName, boolean isChangeOwner, boolean withForce) {
     if (isBlocked(permissionName, isChangeOwner, withForce)) {
-      logger.atFine().log(
+      if (logger.atFine().isEnabled() || LoggingContext.getInstance().isAclLogging()) {
-          "'%s' cannot perform '%s' with force=%s on project '%s' for ref '%s'"
+        String logMessage =
-              + " because this permission is blocked (caller: %s)",
+            String.format(
-          getUser().getLoggableName(),
+                "'%s' cannot perform '%s' with force=%s on project '%s' for ref '%s'"
-          permissionName,
+                    + " because this permission is blocked",
-          withForce,
+                getUser().getLoggableName(),
-          projectControl.getProject().getName(),
+                permissionName,
-          refName,
+                withForce,
-          callerFinder.findCallerLazy());
+                projectControl.getProject().getName(),
+                refName);
+        LoggingContext.getInstance().addAclLogRecord(logMessage);
+        logger.atFine().log("%s (caller: %s)", logMessage, callerFinder.findCallerLazy());
+      }
       return false;
     }
 
     for (PermissionRule pr : relevant.getAllowRules(permissionName)) {
       if (isAllow(pr, withForce) && projectControl.match(pr, isChangeOwner)) {
-        logger.atFine().log(
+        if (logger.atFine().isEnabled() || LoggingContext.getInstance().isAclLogging()) {
-            "'%s' can perform '%s' with force=%s on project '%s' for ref '%s' (caller: %s)",
+          String logMessage =
-            getUser().getLoggableName(),
+              String.format(
-            permissionName,
+                  "'%s' can perform '%s' with force=%s on project '%s' for ref '%s'",
-            withForce,
+                  getUser().getLoggableName(),
-            projectControl.getProject().getName(),
+                  permissionName,
-            refName,
+                  withForce,
-            callerFinder.findCallerLazy());
+                  projectControl.getProject().getName(),
+                  refName);
+          LoggingContext.getInstance().addAclLogRecord(logMessage);
+          logger.atFine().log("%s (caller: %s)", logMessage, callerFinder.findCallerLazy());
+        }
         return true;
       }
     }
 
-    logger.atFine().log(
+    if (logger.atFine().isEnabled() || LoggingContext.getInstance().isAclLogging()) {
-        "'%s' cannot perform '%s' with force=%s on project '%s' for ref '%s' (caller: %s)",
+      String logMessage =
-        getUser().getLoggableName(),
+          String.format(
-        permissionName,
+              "'%s' cannot perform '%s' with force=%s on project '%s' for ref '%s'",
-        withForce,
+              getUser().getLoggableName(),
-        projectControl.getProject().getName(),
+              permissionName,
-        refName,
+              withForce,
-        callerFinder.findCallerLazy());
+              projectControl.getProject().getName(),
+              refName);
+      LoggingContext.getInstance().addAclLogRecord(logMessage);
+      logger.atFine().log("%s (caller: %s)", logMessage, callerFinder.findCallerLazy());
+    }
     return false;
   }
 

java/com/google/gerrit/server/restapi/project/CheckAccess.java

@@ -28,6 +28,7 @@ import com.google.gerrit.extensions.restapi.RestApiException;
 import com.google.gerrit.extensions.restapi.RestModifyView;
 import com.google.gerrit.server.account.AccountResolver;
 import com.google.gerrit.server.git.GitRepositoryManager;
+import com.google.gerrit.server.logging.TraceContext;
 import com.google.gerrit.server.permissions.DefaultPermissionMappings;
 import com.google.gerrit.server.permissions.GlobalPermission;
 import com.google.gerrit.server.permissions.PermissionBackend;
@@ -73,60 +74,74 @@ public class CheckAccess implements RestModifyView<ProjectResource, AccessCheckI
       throw new BadRequestException("input requires 'account'");
     }
 
-    Account.Id match = accountResolver.resolve(input.account).asUnique().account().id();
+    try (TraceContext traceContext = TraceContext.open()) {
+      traceContext.enableAclLogging();
 
-    AccessCheckInfo info = new AccessCheckInfo();
+      Account.Id match = accountResolver.resolve(input.account).asUnique().account().id();
-    try {
-      permissionBackend
-          .absentUser(match)
-          .project(rsrc.getNameKey())
-          .check(ProjectPermission.ACCESS);
-    } catch (AuthException e) {
-      info.message = String.format("user %s cannot see project %s", match, rsrc.getName());
-      info.status = HttpServletResponse.SC_FORBIDDEN;
-      return Response.ok(info);
-    }
 
-    RefPermission refPerm;
-    if (!Strings.isNullOrEmpty(input.permission)) {
-      if (Strings.isNullOrEmpty(input.ref)) {
-        throw new BadRequestException("must set 'ref' when specifying 'permission'");
-      }
-      Optional<RefPermission> rp = DefaultPermissionMappings.refPermission(input.permission);
-      if (!rp.isPresent()) {
-        throw new BadRequestException(
-            String.format("'%s' is not recognized as ref permission", input.permission));
-      }
-
-      refPerm = rp.get();
-    } else {
-      refPerm = RefPermission.READ;
-    }
-
-    if (!Strings.isNullOrEmpty(input.ref)) {
       try {
         permissionBackend
             .absentUser(match)
-            .ref(BranchNameKey.create(rsrc.getNameKey(), input.ref))
+            .project(rsrc.getNameKey())
-            .check(refPerm);
+            .check(ProjectPermission.ACCESS);
       } catch (AuthException e) {
-        info.status = HttpServletResponse.SC_FORBIDDEN;
+        return Response.ok(
-        info.message =
+            createInfo(
-            String.format(
+                traceContext,
-                "user %s lacks permission %s for %s in project %s",
+                HttpServletResponse.SC_FORBIDDEN,
-                match, input.permission, input.ref, rsrc.getName());
+                String.format("user %s cannot see project %s", match, rsrc.getName())));
-        return Response.ok(info);
       }
-    } else {
+
-      // We say access is okay if there are no refs, but this warrants a warning,
+      RefPermission refPerm;
-      // as access denied looks the same as no branches to the user.
+      if (!Strings.isNullOrEmpty(input.permission)) {
-      try (Repository repo = gitRepositoryManager.openRepository(rsrc.getNameKey())) {
+        if (Strings.isNullOrEmpty(input.ref)) {
-        if (repo.getRefDatabase().getRefsByPrefix(REFS_HEADS).isEmpty()) {
+          throw new BadRequestException("must set 'ref' when specifying 'permission'");
-          info.message = "access is OK, but repository has no branches under refs/heads/";
+        }
+        Optional<RefPermission> rp = DefaultPermissionMappings.refPermission(input.permission);
+        if (!rp.isPresent()) {
+          throw new BadRequestException(
+              String.format("'%s' is not recognized as ref permission", input.permission));
+        }
+
+        refPerm = rp.get();
+      } else {
+        refPerm = RefPermission.READ;
+      }
+
+      String message = null;
+      if (!Strings.isNullOrEmpty(input.ref)) {
+        try {
+          permissionBackend
+              .absentUser(match)
+              .ref(BranchNameKey.create(rsrc.getNameKey(), input.ref))
+              .check(refPerm);
+        } catch (AuthException e) {
+          return Response.ok(
+              createInfo(
+                  traceContext,
+                  HttpServletResponse.SC_FORBIDDEN,
+                  String.format(
+                      "user %s lacks permission %s for %s in project %s",
+                      match, input.permission, input.ref, rsrc.getName())));
+        }
+      } else {
+        // We say access is okay if there are no refs, but this warrants a warning,
+        // as access denied looks the same as no branches to the user.
+        try (Repository repo = gitRepositoryManager.openRepository(rsrc.getNameKey())) {
+          if (repo.getRefDatabase().getRefsByPrefix(REFS_HEADS).isEmpty()) {
+            message = "access is OK, but repository has no branches under refs/heads/";
+          }
         }
       }
+      return Response.ok(createInfo(traceContext, HttpServletResponse.SC_OK, message));
     }
-    info.status = HttpServletResponse.SC_OK;
+  }
-    return Response.ok(info);
+
+  private AccessCheckInfo createInfo(TraceContext traceContext, int statusCode, String message) {
+    AccessCheckInfo info = new AccessCheckInfo();
+    info.status = statusCode;
+    info.message = message;
+    info.debugLogs = traceContext.getAclLogRecords();
+    return info;
   }
 }

javatests/com/google/gerrit/acceptance/api/project/CheckAccessIT.java

@@ -162,28 +162,37 @@ public class CheckAccessIT extends AbstractDaemonTest {
     String project;
     String permission;
     int want;
+    List<String> expectedDebugLogs;
 
-    static TestCase project(String mail, String project, int want) {
+    static TestCase project(String mail, String project, int want, List<String> expectedDebugLogs) {
       TestCase t = new TestCase();
       t.input = new AccessCheckInput();
       t.input.account = mail;
       t.project = project;
       t.want = want;
+      t.expectedDebugLogs = expectedDebugLogs;
       return t;
     }
 
-    static TestCase projectRef(String mail, String project, String ref, int want) {
+    static TestCase projectRef(
+        String mail, String project, String ref, int want, List<String> expectedDebugLogs) {
       TestCase t = new TestCase();
       t.input = new AccessCheckInput();
       t.input.account = mail;
       t.input.ref = ref;
       t.project = project;
       t.want = want;
+      t.expectedDebugLogs = expectedDebugLogs;
       return t;
     }
 
     static TestCase projectRefPerm(
-        String mail, String project, String ref, String permission, int want) {
+        String mail,
+        String project,
+        String ref,
+        String permission,
+        int want,
+        List<String> expectedDebugLogs) {
       TestCase t = new TestCase();
       t.input = new AccessCheckInput();
       t.input.account = mail;
@@ -191,6 +200,7 @@ public class CheckAccessIT extends AbstractDaemonTest {
       t.input.permission = permission;
       t.project = project;
       t.want = want;
+      t.expectedDebugLogs = expectedDebugLogs;
       return t;
     }
   }
@@ -217,27 +227,98 @@ public class CheckAccessIT extends AbstractDaemonTest {
                 normalProject.get(),
                 "refs/heads/master",
                 Permission.VIEW_PRIVATE_CHANGES,
-                403),
+                403,
-            TestCase.project(user.email(), normalProject.get(), 200),
+                ImmutableList.of(
-            TestCase.project(user.email(), secretProject.get(), 403),
+                    "'user' can perform 'read' with force=false on project '"
+                        + normalProject.get()
+                        + "' for ref 'refs/*'",
+                    "'user' cannot perform 'viewPrivateChanges' with force=false on project '"
+                        + normalProject.get()
+                        + "' for ref 'refs/heads/master'")),
+            TestCase.project(
+                user.email(),
+                normalProject.get(),
+                200,
+                ImmutableList.of(
+                    "'user' can perform 'read' with force=false on project '"
+                        + normalProject.get()
+                        + "' for ref 'refs/*'")),
+            TestCase.project(
+                user.email(),
+                secretProject.get(),
+                403,
+                ImmutableList.of(
+                    "'user' cannot perform 'read' with force=false on project '"
+                        + secretProject.get()
+                        + "' for ref 'refs/*' because this permission is blocked")),
             TestCase.projectRef(
-                user.email(), secretRefProject.get(), "refs/heads/secret/master", 403),
+                user.email(),
+                secretRefProject.get(),
+                "refs/heads/secret/master",
+                403,
+                ImmutableList.of(
+                    "'user' can perform 'read' with force=false on project '"
+                        + secretRefProject.get()
+                        + "' for ref 'refs/heads/*'",
+                    "'user' cannot perform 'read' with force=false on project '"
+                        + secretRefProject.get()
+                        + "' for ref 'refs/heads/secret/master' because this permission is blocked")),
             TestCase.projectRef(
-                privilegedUser.email(), secretRefProject.get(), "refs/heads/secret/master", 200),
+                privilegedUser.email(),
-            TestCase.projectRef(privilegedUser.email(), normalProject.get(), null, 200),
+                secretRefProject.get(),
-            TestCase.projectRef(privilegedUser.email(), secretProject.get(), null, 200),
+                "refs/heads/secret/master",
+                200,
+                ImmutableList.of(
+                    "'privilegedUser' can perform 'read' with force=false on project '"
+                        + secretRefProject.get()
+                        + "' for ref 'refs/heads/*'",
+                    "'privilegedUser' can perform 'read' with force=false on project '"
+                        + secretRefProject.get()
+                        + "' for ref 'refs/heads/secret/master'")),
+            TestCase.projectRef(
+                privilegedUser.email(),
+                normalProject.get(),
+                null,
+                200,
+                ImmutableList.of(
+                    "'privilegedUser' can perform 'read' with force=false on project '"
+                        + normalProject.get()
+                        + "' for ref 'refs/*'")),
+            TestCase.projectRef(
+                privilegedUser.email(),
+                secretProject.get(),
+                null,
+                200,
+                ImmutableList.of(
+                    "'privilegedUser' can perform 'read' with force=false on project '"
+                        + secretProject.get()
+                        + "' for ref 'refs/*'")),
             TestCase.projectRefPerm(
                 privilegedUser.email(),
                 normalProject.get(),
                 "refs/heads/master",
                 Permission.VIEW_PRIVATE_CHANGES,
-                200),
+                200,
+                ImmutableList.of(
+                    "'privilegedUser' can perform 'read' with force=false on project '"
+                        + normalProject.get()
+                        + "' for ref 'refs/*'",
+                    "'privilegedUser' can perform 'viewPrivateChanges' with force=false on project '"
+                        + normalProject.get()
+                        + "' for ref 'refs/heads/master'")),
             TestCase.projectRefPerm(
                 privilegedUser.email(),
                 normalProject.get(),
                 "refs/heads/master",
                 Permission.FORGE_SERVER,
-                200));
+                200,
+                ImmutableList.of(
+                    "'privilegedUser' can perform 'read' with force=false on project '"
+                        + normalProject.get()
+                        + "' for ref 'refs/*'",
+                    "'privilegedUser' can perform 'forgeServerAsCommitter' with force=false on project '"
+                        + normalProject.get()
+                        + "' for ref 'refs/heads/master'")));
 
     for (TestCase tc : inputs) {
       String in = newGson().toJson(tc.input);
@@ -273,6 +354,14 @@ public class CheckAccessIT extends AbstractDaemonTest {
         default:
           assertWithMessage(String.format("unknown code %d", want)).fail();
       }
+
+      if (!info.debugLogs.equals(tc.expectedDebugLogs)) {
+        assertWithMessage(
+                String.format(
+                    "check.access(%s, %s) = %s, want %s",
+                    tc.project, in, info.debugLogs, tc.expectedDebugLogs))
+            .fail();
+      }
     }
   }