Adding debug logs for request creation and checkACL failure

linkedin · Apr 29, 2022 · a55e786 · a55e786
1 parent 9701911
commit a55e786
Show file tree

Hide file tree

Showing 6 changed files with 19 additions and 1 deletion.
diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/PrepRequestProcessor.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/PrepRequestProcessor.java
@@ -1024,13 +1024,15 @@ public static List<ACL> fixupACL(String path, List<Id> authInfo, List<ACL> acls)
                     if (ap == null) {
                         LOG.error("Missing AuthenticationProvider for {}", cid.getScheme());
                     } else if (ap.isAuthenticated()) {
+                        LOG.debug("Authenticated successfully : {} {}", a, cid);
                         authIdValid = true;
                         rv.add(new ACL(a.getPerms(), cid));
                     }
                 }
                 // If the znode path contains open read access node path prefix, add (world:anyone, r)
                 if (X509AuthenticationConfig.getInstance().getZnodeGroupAclOpenReadAccessPathPrefixes().stream()
                     .anyMatch(path::startsWith)) {
+                    LOG.debug("Found open read access");
                     rv.add(new ACL(ZooDefs.Perms.READ, ZooDefs.Ids.ANYONE_ID_UNSAFE));
                 }
 
@@ -1045,6 +1047,7 @@ public static List<ACL> fixupACL(String path, List<Id> authInfo, List<ACL> acls)
                 rv.add(a);
             }
         }
+        LOG.debug("returning rv : {}", rv);
         return rv;
     }
 

diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZKDatabase.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZKDatabase.java
@@ -304,6 +304,7 @@ public long fastForwardDataBase() throws IOException {
     }
 
     private void addCommittedProposal(TxnHeader hdr, Record txn, TxnDigest digest) {
+        LOG.debug("Creating a committed proposal request with null cnxn");
         Request r = new Request(0, hdr.getCxid(), hdr.getType(), hdr, txn, hdr.getZxid());
         r.setTxnDigest(digest);
         addCommittedProposal(r);

diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServer.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServer.java
@@ -976,6 +976,7 @@ long createSession(ServerCnxn cnxn, byte[] passwd, int timeout) {
         ByteBuffer to = ByteBuffer.allocate(4);
         to.putInt(timeout);
         cnxn.setSessionId(sessionId);
+        LOG.debug("Creating a new request for session");
         Request si = new Request(cnxn, sessionId, 0, OpCode.createSession, to, null);
         submitRequest(si);
         return sessionId;
@@ -1596,7 +1597,7 @@ public void processPacket(ServerCnxn cnxn, ByteBuffer incomingBuffer) throws IOE
                         new ServerAuthenticationProvider.ServerObjs(this, cnxn),
                         authPacket.getAuth());
                 } catch (RuntimeException e) {
-                    LOG.warn("Caught runtime exception from AuthenticationProvider: {}", scheme, e);
+                    LOG.warn("Caught runtime exception from AuthenticationProvider: {} {}", scheme, e);
                     authReturn = KeeperException.Code.AUTHFAILED;
                 }
             }
@@ -1631,6 +1632,7 @@ public void processPacket(ServerCnxn cnxn, ByteBuffer incomingBuffer) throws IOE
                 cnxn.sendCloseSession();
                 cnxn.disableRecv();
             } else {
+                LOG.debug("Creating a connection request with cnxn for session : {} auth info : {}", cnxn.getSessionId(), cnxn.getAuthInfo());
                 Request si = new Request(cnxn, cnxn.getSessionId(), h.getXid(), h.getType(), incomingBuffer, cnxn.getAuthInfo());
                 int length = incomingBuffer.limit();
                 if (isLargeRequest(length)) {
@@ -1937,16 +1939,19 @@ public void checkACL(ServerCnxn cnxn, List<ACL> acl, int perm, List<Id> ids, Str
         LOG.debug("Permission requested: {} ", perm);
         LOG.debug("ACLs for node: {}", acl);
         LOG.debug("Client credentials: {}", ids);
+        LOG.debug("Cnxn : {}", cnxn);
 
         if (acl == null || acl.size() == 0) {
             return;
         }
         for (Id authId : ids) {
             if (authId.getScheme().equals("super")) {
+                LOG.debug("Found super scheme returning from here");
                 return;
             }
         }
         for (ACL a : acl) {
+            LOG.debug("Iterating ACLs: {}", a);
             Id id = a.getId();
             if ((a.getPerms() & perm) != 0) {
                 if (id.getScheme().equals("world") && id.getId().equals("anyone")) {
@@ -1955,6 +1960,7 @@ public void checkACL(ServerCnxn cnxn, List<ACL> acl, int perm, List<Id> ids, Str
                 ServerAuthenticationProvider ap = ProviderRegistry.getServerProvider(id.getScheme());
                 if (ap != null) {
                     for (Id authId : ids) {
+                        LOG.debug("Iterating IDs : {}", authId);
                         if (authId.getScheme().equals(id.getScheme())
                             && ap.matches(
                                 new ServerAuthenticationProvider.ServerObjs(this, cnxn),

diff --git a/.../main/java/org/apache/zookeeper/server/auth/znode/groupacl/X509ZNodeGroupAclProvider.java b/.../main/java/org/apache/zookeeper/server/auth/znode/groupacl/X509ZNodeGroupAclProvider.java
@@ -118,6 +118,12 @@ public KeeperException.Code handleAuthentication(ServerObjs serverObjs, byte[] a
 
   @Override
   public boolean matches(ServerObjs serverObjs, MatchValues matchValues) {
+    LOG.debug("Server obj cnxn : {}", serverObjs.getCnxn());
+    if (serverObjs.getCnxn() != null) {
+      LOG.debug("Auth info in cnxn obj : {}", serverObjs.getCnxn().getAuthInfo());
+    } else {
+      LOG.debug("Found null cnxn");
+    }
     for (Id id : serverObjs.getCnxn().getAuthInfo()) {
       // Not checking for super user here because the check is already covered
       // in checkAcl() in ZookeeperServer.class

diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/Learner.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/Learner.java
@@ -788,6 +788,7 @@ protected void syncWithLeader(long newLeaderZxid) throws Exception {
                     continue;
                 }
                 packetsCommitted.remove();
+                LOG.debug("Creating request with empty cnxn and empty authinfo");
                 Request request = new Request(null, p.hdr.getClientId(), p.hdr.getCxid(), p.hdr.getType(), null, null);
                 request.setTxn(p.rec);
                 request.setHdr(p.hdr);

diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/LearnerHandler.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/LearnerHandler.java
@@ -698,6 +698,7 @@ public void run() {
                     if (type == OpCode.sync) {
                         si = new LearnerSyncRequest(this, sessionId, cxid, type, bb, qp.getAuthinfo());
                     } else {
+                        LOG.debug("Creating request with null cnxn and authinfo : {}", qp.getAuthinfo());
                         si = new Request(null, sessionId, cxid, type, bb, qp.getAuthinfo());
                     }
                     si.setOwner(this);