HADOOP-13903. Improvements to KMS logging to help debug authorization errors. (Tristan Stevens via asuresh)

hadoop-common-project/hadoop-kms/src/main/java/org/apache/hadoop/crypto/key/kms/server/KMSACLs.java

@@ -236,9 +236,26 @@ public class KMSACLs implements Runnable, KeyACLs {
    */
   public boolean hasAccess(Type type, UserGroupInformation ugi) {
     boolean access = acls.get(type).isUserAllowed(ugi);
+    if (LOG.isDebugEnabled()) {
+      LOG.debug("Checking user [{}] for: {} {} ", ugi.getShortUserName(),
+          type.toString(), acls.get(type).getAclString());
+    }
     if (access) {
       AccessControlList blacklist = blacklistedAcls.get(type);
       access = (blacklist == null) || !blacklist.isUserInList(ugi);
+      if (LOG.isDebugEnabled()) {
+        if (blacklist == null) {
+          LOG.debug("No blacklist for {}", type.toString());
+        } else if (access) {
+          LOG.debug("user is in {}" , blacklist.getAclString());
+        } else {
+          LOG.debug("user is not in {}" , blacklist.getAclString());
+        }
+      }
+    }
+    if (LOG.isDebugEnabled()) {
+      LOG.debug("User: [{}], Type: {} Result: {}", ugi.getShortUserName(),
+          type.toString(), access);
     }
     return access;
   }
@@ -259,8 +276,12 @@ public class KMSACLs implements Runnable, KeyACLs {
   @Override
   public boolean hasAccessToKey(String keyName, UserGroupInformation ugi,
       KeyOpType opType) {
-    return checkKeyAccess(keyName, ugi, opType)
+    boolean access = checkKeyAccess(keyName, ugi, opType)
         || checkKeyAccess(whitelistKeyAcls, ugi, opType);
+    if (!access) {
+      KMSWebApp.getKMSAudit().unauthorized(ugi, opType, keyName);
+    }
+    return access;
   }
 
   private boolean checkKeyAccess(String keyName, UserGroupInformation ugi,
@@ -269,9 +290,15 @@ public class KMSACLs implements Runnable, KeyACLs {
     if (keyAcl == null) {
       // If No key acl defined for this key, check to see if
       // there are key defaults configured for this operation
+      LOG.debug("Key: {} has no ACLs defined, using defaults.", keyName);
       keyAcl = defaultKeyAcls;
     }
-    return checkKeyAccess(keyAcl, ugi, opType);
+    boolean access = checkKeyAccess(keyAcl, ugi, opType);
+    if (LOG.isDebugEnabled()) {
+      LOG.debug("User: [{}], OpType: {}, KeyName: {} Result: {}",
+          ugi.getShortUserName(), opType.toString(), keyName, access);
+    }
+    return access;
   }
 
   private boolean checkKeyAccess(Map<KeyOpType, AccessControlList> keyAcl,
@@ -280,8 +307,13 @@ public class KMSACLs implements Runnable, KeyACLs {
     if (acl == null) {
       // If no acl is specified for this operation,
       // deny access
+      LOG.debug("No ACL available for key, denying access for {}", opType);
       return false;
     } else {
+      if (LOG.isDebugEnabled()) {
+        LOG.debug("Checking user [{}] for: {}: {}" + ugi.getShortUserName(),
+            opType.toString(), acl.getAclString());
+      }
       return acl.isUserAllowed(ugi);
     }
   }

hadoop-common-project/hadoop-kms/src/main/java/org/apache/hadoop/crypto/key/kms/server/KMSAudit.java

@@ -23,6 +23,8 @@ import static org.apache.hadoop.crypto.key.kms.server.KMSAuditLogger.OpStatus;
 import com.google.common.annotations.VisibleForTesting;
 import com.google.common.base.Preconditions;
 import org.apache.hadoop.conf.Configuration;
+import org.apache.hadoop.crypto.key.kms.server.KMSACLs.Type;
+import org.apache.hadoop.crypto.key.kms.server.KeyAuthorizationKeyProvider.KeyOpType;
 import org.apache.hadoop.security.UserGroupInformation;
 import org.apache.hadoop.util.ReflectionUtils;
 import org.apache.hadoop.util.Time;
@@ -168,7 +170,25 @@ public class KMSAudit {
     }
   }
 
-  private void op(final OpStatus opStatus, final KMS.KMSOp op,
+  /**
+   * Logs to the audit service a single operation on the KMS or on a key.
+   *
+   * @param opStatus
+   *          The outcome of the audited event
+   * @param op
+   *          The operation being audited (either {@link KMS.KMSOp} or
+   *          {@link Type} N.B this is passed as an {@link Object} to allow
+   *          either enum to be passed in.
+   * @param ugi
+   *          The user's security context
+   * @param key
+   *          The String name of the key if applicable
+   * @param remoteHost
+   *          The hostname of the requesting service
+   * @param extraMsg
+   *          Any extra details for auditing
+   */
+  private void op(final OpStatus opStatus, final Object op,
       final UserGroupInformation ugi, final String key, final String remoteHost,
       final String extraMsg) {
     final String user = ugi == null ? null: ugi.getShortUserName();
@@ -215,6 +235,12 @@ public class KMSAudit {
     op(OpStatus.UNAUTHORIZED, op, user, key, "Unknown", "");
   }
 
+  public void unauthorized(UserGroupInformation user, KeyOpType op,
+      String key) {
+    op(OpStatus.UNAUTHORIZED, op, user, key, "Unknown", "");
+
+  }
+
   public void error(UserGroupInformation user, String method, String url,
       String extraMsg) {
     op(OpStatus.ERROR, null, user, null, "Unknown", "Method:'" + method
@@ -228,7 +254,7 @@ public class KMSAudit {
         + " URL:" + url + " ErrorMsg:'" + extraMsg + "'");
   }
 
-  private static String createCacheKey(String user, String key, KMS.KMSOp op) {
+  private static String createCacheKey(String user, String key, Object op) {
     return user + "#" + key + "#" + op;
   }
 

hadoop-common-project/hadoop-kms/src/main/java/org/apache/hadoop/crypto/key/kms/server/KMSAuditLogger.java

@@ -23,6 +23,7 @@ import java.util.concurrent.atomic.AtomicLong;
 import org.apache.hadoop.classification.InterfaceAudience;
 import org.apache.hadoop.classification.InterfaceStability;
 import org.apache.hadoop.conf.Configuration;
+import org.apache.hadoop.crypto.key.kms.server.KMSACLs.Type;
 import org.apache.hadoop.security.UserGroupInformation;
 
 /**
@@ -46,7 +47,7 @@ interface KMSAuditLogger {
    */
   class AuditEvent {
     private final AtomicLong accessCount = new AtomicLong(-1);
-    private final KMS.KMSOp op;
+    private final Object op;
     private final String keyName;
     private final String user;
     private final String impersonator;
@@ -55,7 +56,21 @@ interface KMSAuditLogger {
     private final long startTime = System.currentTimeMillis();
     private long endTime = startTime;
 
-    AuditEvent(KMS.KMSOp op, UserGroupInformation ugi, String keyName,
+    /**
+     * @param op
+     *          The operation being audited (either {@link KMS.KMSOp} or
+     *          {@link Type} N.B this is passed as an {@link Object} to allow
+     *          either enum to be passed in.
+     * @param ugi
+     *          The user's security context
+     * @param keyName
+     *          The String name of the key if applicable
+     * @param remoteHost
+     *          The hostname of the requesting service
+     * @param msg
+     *          Any extra details for auditing
+     */
+    AuditEvent(Object op, UserGroupInformation ugi, String keyName,
         String remoteHost, String msg) {
       this.keyName = keyName;
       if (ugi == null) {
@@ -79,7 +94,7 @@ interface KMSAuditLogger {
       return accessCount;
     }
 
-    public KMS.KMSOp getOp() {
+    public Object getOp() {
       return op;
     }