From 168587e6cd263ea82cac2f86b5adf463cb6258c3 Mon Sep 17 00:00:00 2001
From: ektavarma10 <ekta.varma@atlan.com>
Date: Thu, 30 Nov 2023 09:43:54 +0530
Subject: [PATCH] Add logs

---
 .../authorizer/RangerAtlasAuthorizer.java     | 34 ++++++++++---------
 1 file changed, 18 insertions(+), 16 deletions(-)

diff --git a/auth-plugin-atlas/src/main/java/org/apache/atlas/authorization/atlas/authorizer/RangerAtlasAuthorizer.java b/auth-plugin-atlas/src/main/java/org/apache/atlas/authorization/atlas/authorizer/RangerAtlasAuthorizer.java
index 0fbc9494280..520fc017e72 100644
--- a/auth-plugin-atlas/src/main/java/org/apache/atlas/authorization/atlas/authorizer/RangerAtlasAuthorizer.java
+++ b/auth-plugin-atlas/src/main/java/org/apache/atlas/authorization/atlas/authorizer/RangerAtlasAuthorizer.java
@@ -54,15 +54,8 @@
 import org.apache.atlas.plugin.util.RangerPerfTracer;
 
 import java.awt.*;
-import java.util.Collection;
-import java.util.Collections;
-import java.util.HashMap;
-import java.util.HashSet;
+import java.util.*;
 import java.util.List;
-import java.util.ListIterator;
-import java.util.Map;
-import java.util.Set;
-import java.util.ArrayList;
 import java.util.concurrent.CompletableFuture;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
@@ -254,7 +247,7 @@ public boolean isAccessAllowed(AtlasTypeAccessRequest request) throws AtlasAutho
             boolean isAuditDisabled = ACCESS_TYPE_TYPE_READ.equalsIgnoreCase(action);
 
             if (isAuditDisabled) {
-                ret = checkAccess(rangerRequest, null);
+                ret = checkAccess(rangerRequest, null, "");
             } else {
                 ret = checkAccess(rangerRequest);
             }
@@ -661,8 +654,10 @@ private boolean isAccessAllowed(AtlasEntityAccessRequest request, RangerAtlasAud
         if (LOG.isDebugEnabled()) {
             LOG.debug("==> isAccessAllowed(" + request + ")");
         }
+
+        String uuid = UUID.randomUUID().toString();
         long startTime = System.currentTimeMillis();
-        LOG.info("start isAccessAllowed : " + startTime);
+        LOG.info("start isAccessAllowed : " + startTime + " uuid: " + uuid);
         boolean ret = false;
 
         try {
@@ -675,17 +670,17 @@ private boolean isAccessAllowed(AtlasEntityAccessRequest request, RangerAtlasAud
                 List<CompletableFuture<Boolean>> completableFutures = new ArrayList<>();
 
                 // check authorization for each classification
-                LOG.info("start check authrization for each classification: " + (System.currentTimeMillis() - startTime));
+                LOG.info("start check authrization for each classification: " + (System.currentTimeMillis() - startTime)+ " uuid: " + uuid);
                 for (AtlasClassification classificationToAuthorize : request.getEntityClassifications()) {
 
                     RangerAccessRequestImpl  rangerRequest  = createRangerAccessRequest(request, classificationToAuthorize, rangerTagForEval);
 
-                    completableFutures.add(CompletableFuture.supplyAsync(()->checkAccess(rangerRequest, auditHandler), classificationAccessThreadpool));
+                    completableFutures.add(CompletableFuture.supplyAsync(()->checkAccess(rangerRequest, auditHandler, uuid), classificationAccessThreadpool));
                 }
 
                 // wait for all threads to complete their execution
                 CompletableFuture.allOf(completableFutures.toArray(new CompletableFuture[0])).join();
-                LOG.info("end check authorization for each classification: " + (System.currentTimeMillis() - startTime));
+                LOG.info("end check authorization for each classification: " + (System.currentTimeMillis() - startTime) + " uuid: " + uuid);
 
 
                 // if all checkAccess calls return true, then ret is true, else it is false
@@ -706,7 +701,7 @@ private boolean isAccessAllowed(AtlasEntityAccessRequest request, RangerAtlasAud
 
                 rangerResource.setValue(RESOURCE_ENTITY_CLASSIFICATION, ENTITY_NOT_CLASSIFIED );
 
-                ret = checkAccess(rangerRequest, auditHandler);
+                ret = checkAccess(rangerRequest, auditHandler, uuid);
             }
 
         } finally {
@@ -726,6 +721,9 @@ private RangerAccessRequestImpl createRangerAccessRequest(AtlasEntityAccessReque
                                                               AtlasClassification classificationToAuthorize,
                                                               Set<RangerTagForEval> rangerTagForEval) {
 
+        long startTime = System.currentTimeMillis();
+        LOG.info("createRangerAccessRequest start: " + startTime);
+
         RangerAccessRequestImpl rangerRequest = new RangerAccessRequestImpl();
         RangerAccessResourceImpl rangerResource = new RangerAccessResourceImpl();
 
@@ -738,6 +736,8 @@ private RangerAccessRequestImpl createRangerAccessRequest(AtlasEntityAccessReque
 
         setClassificationContextForRanger(rangerTagForEval, rangerRequest);
 
+        LOG.info("createRangerAccessRequest end: " + (System.currentTimeMillis() - startTime));
+
         return rangerRequest;
 
     }
@@ -851,7 +851,9 @@ private boolean checkAccess(RangerAccessRequestImpl request) {
         return ret;
     }
 
-    private boolean checkAccess(RangerAccessRequestImpl request, RangerAtlasAuditHandler auditHandler) {
+    private boolean checkAccess(RangerAccessRequestImpl request, RangerAtlasAuditHandler auditHandler, String uuid) {
+        long startTime = System.currentTimeMillis();
+        LOG.info("Check Access started: " + startTime+ " uuid: " + uuid);
         boolean          ret    = false;
         
         RangerBasePlugin plugin = atlasPlugin;
@@ -874,7 +876,7 @@ private boolean checkAccess(RangerAccessRequestImpl request, RangerAtlasAuditHan
         } else {
             LOG.warn("RangerAtlasPlugin not initialized. Access blocked!!!");
         }
-
+        LOG.info("Check Access ended: " + (System.currentTimeMillis()-startTime)+ "uuid: " + uuid);
         return ret;
     }