Merge "CheckAccess: Return ACL debug logs"

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
-   * records that are added in the new thread are added to the same {@link
-   * MutablePerformanceLogRecords} instance (see {@link LoggingContextAwareRunnable} and {@link
+   * When copying the logging context to a new thread we need to ensure that the mutable log records
+   * (performance logs and ACL logs) that are added in the new thread are added to the same multable
+   * 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(
-          "'%s' cannot perform '%s' with force=%s on project '%s' for ref '%s'"
-              + " because this permission is blocked (caller: %s)",
-          getUser().getLoggableName(),
-          permissionName,
-          withForce,
-          projectControl.getProject().getName(),
-          refName,
-          callerFinder.findCallerLazy());
+      if (logger.atFine().isEnabled() || LoggingContext.getInstance().isAclLogging()) {
+        String logMessage =
+            String.format(
+                "'%s' cannot perform '%s' with force=%s on project '%s' for ref '%s'"
+                    + " because this permission is blocked",
+                getUser().getLoggableName(),
+                permissionName,
+                withForce,
+                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(
-            "'%s' can perform '%s' with force=%s on project '%s' for ref '%s' (caller: %s)",
-            getUser().getLoggableName(),
-            permissionName,
-            withForce,
-            projectControl.getProject().getName(),
-            refName,
-            callerFinder.findCallerLazy());
+        if (logger.atFine().isEnabled() || LoggingContext.getInstance().isAclLogging()) {
+          String logMessage =
+              String.format(
+                  "'%s' can perform '%s' with force=%s on project '%s' for ref '%s'",
+                  getUser().getLoggableName(),
+                  permissionName,
+                  withForce,
+                  projectControl.getProject().getName(),
+                  refName);
+          LoggingContext.getInstance().addAclLogRecord(logMessage);
+          logger.atFine().log("%s (caller: %s)", logMessage, callerFinder.findCallerLazy());
+        }
         return true;
       }
     }
 
-    logger.atFine().log(
-        "'%s' cannot perform '%s' with force=%s on project '%s' for ref '%s' (caller: %s)",
-        getUser().getLoggableName(),
-        permissionName,
-        withForce,
-        projectControl.getProject().getName(),
-        refName,
-        callerFinder.findCallerLazy());
+    if (logger.atFine().isEnabled() || LoggingContext.getInstance().isAclLogging()) {
+      String logMessage =
+          String.format(
+              "'%s' cannot perform '%s' with force=%s on project '%s' for ref '%s'",
+              getUser().getLoggableName(),
+              permissionName,
+              withForce,
+              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();
-    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);
-    }
+      Account.Id match = accountResolver.resolve(input.account).asUnique().account().id();
 
-    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))
-            .check(refPerm);
+            .project(rsrc.getNameKey())
+            .check(ProjectPermission.ACCESS);
       } catch (AuthException e) {
-        info.status = HttpServletResponse.SC_FORBIDDEN;
-        info.message =
-            String.format(
-                "user %s lacks permission %s for %s in project %s",
-                match, input.permission, input.ref, rsrc.getName());
-        return Response.ok(info);
+        return Response.ok(
+            createInfo(
+                traceContext,
+                HttpServletResponse.SC_FORBIDDEN,
+                String.format("user %s cannot see project %s", match, 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()) {
-          info.message = "access is OK, but repository has no branches under refs/heads/";
+
+      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;
+      }
+
+      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),
-            TestCase.project(user.email(), normalProject.get(), 200),
-            TestCase.project(user.email(), secretProject.get(), 403),
+                403,
+                ImmutableList.of(
+                    "'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),
-            TestCase.projectRef(privilegedUser.email(), normalProject.get(), null, 200),
-            TestCase.projectRef(privilegedUser.email(), secretProject.get(), null, 200),
+                privilegedUser.email(),
+                secretRefProject.get(),
+                "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();
+      }
     }
   }