t72866: updated profiling

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/ldap/LdapConnectionPool.java

@@ -69,6 +69,7 @@
 
 package ca.nrc.cadc.ac.server.ldap;
 
+import com.unboundid.ldap.sdk.SearchResult;
 import org.apache.log4j.Logger;
 
 import ca.nrc.cadc.ac.server.ldap.LdapConfig.LdapPool;
@@ -107,8 +108,6 @@ public class LdapConnectionPool
         OFFLINE
     };
 
-    Profiler profiler = new Profiler(LdapConnectionPool.class);
-
     protected LdapConfig currentConfig;
     private String poolName;
     private LDAPConnectionPool pool;
@@ -137,6 +136,7 @@ public class LdapConnectionPool
         logger.debug("Construct pool: " + poolName + ". system state: " + systemState);
         if (SystemState.ONLINE.equals(systemState) || (SystemState.READONLY.equals(systemState) && readOnly))
         {
+            Profiler profiler = new Profiler(LdapConnectionPool.class);
             synchronized (poolMonitor)
             {
                 if (!boundPool)
@@ -176,23 +176,27 @@ public class LdapConnectionPool
 
         try
         {
+            Profiler profiler = new Profiler(LdapConnectionPool.class);
             LDAPConnection conn = null;
             synchronized (poolMonitor)
             {
                 conn = pool.getConnection();
-                profiler.checkpoint("pool.getConnection");
 
                 // BM: This query to the base dn (starting at dc=) has the
                 // effect of clearing any proxied authorization state associated
                 // with the receiving ldap server connection.  Without this in
                 // place, proxied authorization information is sometimes ignored.
-                logger.debug("Testing connection");
-                int dcIndex = currentConfig.getGroupsDN().indexOf("dc=");
-                String dcDN = currentConfig.getGroupsDN().substring(dcIndex);
-                Filter filter = Filter.createEqualityFilter("dc", "*");
-                SearchRequest searchRequest = new SearchRequest(dcDN, SearchScope.BASE, filter, new String[] {"entrydn"});
-                conn.search(searchRequest);
-                profiler.checkpoint("pool.initConnection");
+//                logger.debug("Testing connection");
+//                int index = currentConfig.getGroupsDN().indexOf(',');
+//                String rdn = currentConfig.getGroupsDN().substring(0, index);
+//                Filter filter = Filter.create("(" + rdn + ")");
+//
+//                index = rdn.indexOf('=');
+//                String attribute = rdn.substring(0, index);
+//
+//                SearchRequest searchRequest = new SearchRequest(currentConfig.getGroupsDN(), SearchScope.BASE, filter, new String[] {attribute});
+//                conn.search(searchRequest);
+//                profiler.checkpoint("pool.initConnection");
             }
             logger.debug(poolName + " pool statistics after borrow:\n" + pool.getConnectionPoolStatistics());
             profiler.checkpoint("get " + poolName + " only connection");
@@ -210,7 +214,9 @@ public class LdapConnectionPool
     {
         if (pool != null)
         {
+            Profiler profiler = new Profiler(LdapConnectionPool.class);
             pool.releaseConnection(conn);
+            profiler.checkpoint("pool.releaseConnection");
             logger.debug(poolName + " pool statistics after release:\n" + pool.getConnectionPoolStatistics());
         }
     }
@@ -225,8 +231,9 @@ public class LdapConnectionPool
         if (pool != null)
         {
             logger.debug("Closing pool...");
+            Profiler profiler = new Profiler(LdapConnectionPool.class);
             pool.close();
-            profiler.checkpoint("Pool closed.");
+            profiler.checkpoint("pool.shutdown");
         }
     }
 

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/ldap/LdapConnections.java

@@ -91,8 +91,6 @@ class LdapConnections
 {
     private final static Logger log = Logger.getLogger(LdapConnections.class);
 
-    Profiler profiler = new Profiler(LdapConnections.class);
-
     private LdapPersistence persistence;
     private LdapConfig config;
 
@@ -134,6 +132,7 @@ class LdapConnections
             if (autoConfigReadOnlyConn == null)
             {
                 log.debug("Getting new auto config read only connection.");
+                Profiler profiler = new Profiler(LdapConnections.class);
                 autoConfigReadOnlyConn = readOnlyPool.getConnection();
                 profiler.checkpoint("Get read only connection");
             }
@@ -173,6 +172,7 @@ class LdapConnections
             if (autoConfigReadWriteConn == null)
             {
                 log.debug("Getting new auto config read write connection.");
+                Profiler profiler = new Profiler(LdapConnections.class);
                 autoConfigReadWriteConn = readWritePool.getConnection();
                 profiler.checkpoint("Get read write connection");
             }
@@ -212,6 +212,7 @@ class LdapConnections
             if (autoConfigUnboundReadOnlyConn == null)
             {
                 log.debug("Getting new auto config unbound read only connection.");
+                Profiler profiler = new Profiler(LdapConnections.class);
                 autoConfigUnboundReadOnlyConn = unboundReadOnlyPool.getConnection();
                 profiler.checkpoint("Get read write connection");
             }
@@ -242,6 +243,7 @@ class LdapConnections
 
     void releaseConnections()
     {
+        Profiler profiler = new Profiler(LdapConnections.class);
         if (persistence != null)
         {
             if (autoConfigReadOnlyConn != null)

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/ldap/LdapDAO.java

@@ -103,8 +103,6 @@ public abstract class LdapDAO
 
     DN subjDN = null;
 
-    private Profiler profiler = new Profiler(LdapDAO.class);
-
     public LdapDAO(LdapConnections connections)
     {
         this.connections = connections;
@@ -192,8 +190,8 @@ public abstract class LdapDAO
 
         if (config.isSecure())
         {
-            socketFactory = createSSLSocketFactory();
             Profiler profiler = new Profiler(LdapDAO.class);
+            socketFactory = createSSLSocketFactory();
             profiler.checkpoint("createSSLSocketFactory");
         }
         else

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/ldap/LdapGroupDAO.java

@@ -137,8 +137,6 @@ public class LdapGroupDAO<T extends Principal> extends LdapDAO
                     "modifytimestamp", "description", "uniquemember"
             };
 
-    private final Profiler profiler = new Profiler(LdapGroupDAO.class);
-
     private LdapUserDAO<T> userDAO;
 
     // this gets filled by the LdapgroupPersistence
@@ -396,6 +394,7 @@ public class LdapGroupDAO<T extends Principal> extends LdapDAO
             SearchResult searchResult = null;
             try
             {
+                Profiler profiler = new Profiler(LdapGroupDAO.class);
                 LDAPInterface con = getReadOnlyConnection();
                 profiler.checkpoint("getGroupNames.getConnection");
                 searchResult = con.search(searchRequest);
@@ -414,7 +413,7 @@ public class LdapGroupDAO<T extends Principal> extends LdapDAO
             }
 
             LdapDAO.checkLdapResult(searchResult.getResultCode());
-            profiler.checkpoint("checkLdapResult");
+//            profiler.checkpoint("checkLdapResult");
 
             return groupNames;
         }

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/ldap/LdapPersistence.java

@@ -97,8 +97,6 @@ public abstract class LdapPersistence
     private static final String LDAP_POOL_JNDI_NAME = ConnectionPools.class.getName();
     private static final int POOL_CHECK_INTERVAL_MILLESCONDS = 10000; // 10 seconds
 
-    Profiler profiler = new Profiler(LdapPersistence.class);
-
     // static monitor is required for when multiple LdapPersistence objects
     // are created.
     private static Object jndiMonitor = new Object();
@@ -208,6 +206,7 @@ public abstract class LdapPersistence
                     }
                     if (pools == null)
                     {
+                        Profiler profiler = new Profiler(LdapPersistence.class);
                         LdapConfig config = LdapConfig.getLdapConfig();
                         pools = createPools(config);
                         InitialContext ic = new InitialContext();
@@ -238,6 +237,7 @@ public abstract class LdapPersistence
 
     private ConnectionPools createPools(LdapConfig config)
     {
+        Profiler profiler = new Profiler(LdapPersistence.class);
         Map<String,LdapConnectionPool> poolMap = new HashMap<String,LdapConnectionPool>(3);
         poolMap.put(POOL_READONLY, new LdapConnectionPool(
             config, config.getReadOnlyPool(), POOL_READONLY, true, true));
@@ -276,6 +276,7 @@ public abstract class LdapPersistence
             else
             {
                 logger.debug("Detected ldap configuration change, rebuilding pools");
+                Profiler profiler = new Profiler(LdapPersistence.class);
                 boolean poolRecreated = false;
                 final ConnectionPools oldPools = pools;
                 ConnectionPools newPools = null;

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/ldap/LdapUserDAO.java

@@ -138,8 +138,6 @@ public class LdapUserDAO<T extends Principal> extends LdapDAO
     
     private static final Logger logger = Logger.getLogger(LdapUserDAO.class);
 
-    private final Profiler profiler = new Profiler(LdapUserDAO.class);
-
     // Map of identity type to LDAP attribute
     private final Map<Class<?>, String> userLdapAttrib = new HashMap<Class<?>, String>();
 
@@ -209,7 +207,7 @@ public class LdapUserDAO<T extends Principal> extends LdapDAO
      * @param password password to verify.
      * @return Boolean
      * @throws TransientException
-     * @throws UserNotFoundExceptionjoellama
+     * @throws UserNotFoundException
      */
     public Boolean doLogin(final String username, final String password)
         throws TransientException, UserNotFoundException
@@ -677,8 +675,8 @@ public class LdapUserDAO<T extends Principal> extends LdapDAO
     public User<T> getAugmentedUser(final T userID)
         throws UserNotFoundException, TransientException
     {
+        Profiler profiler = new Profiler(LdapUserDAO.class);
         String searchField = userLdapAttrib.get(userID.getClass());
-        profiler.checkpoint("getAugmentedUser.getSearchField");
         if (searchField == null)
         {
             throw new IllegalArgumentException(
@@ -690,14 +688,14 @@ public class LdapUserDAO<T extends Principal> extends LdapDAO
             Filter notFilter = Filter.createNOTFilter(Filter.createPresenceFilter(LDAP_NSACCOUNTLOCK));
             Filter equalsFilter = Filter.createEqualityFilter(searchField, userID.getName());
             Filter filter = Filter.createANDFilter(notFilter, equalsFilter);
-            profiler.checkpoint("getAugmentedUser.createFilter");
             logger.debug("search filter: " + filter);
 
             SearchRequest searchRequest = new SearchRequest(
                 config.getUsersDN(), SearchScope.ONE, filter, identityAttribs);
-            profiler.checkpoint("getAugmentedUser.createSearchRequest");
 
-            SearchResultEntry searchResult = getReadOnlyConnection().searchForEntry(searchRequest);
+            LDAPConnection con = getReadOnlyConnection();
+            profiler.checkpoint("getAugmentedUser.getReadOnlyConnection");
+            SearchResultEntry searchResult = con.searchForEntry(searchRequest);
             profiler.checkpoint("getAugmentedUser.searchForEntry");
 
             if (searchResult == null)

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/ldap/LdapUserPersistence.java

@@ -90,7 +90,6 @@ import ca.nrc.cadc.profiler.Profiler;
 public class LdapUserPersistence<T extends Principal> extends LdapPersistence implements UserPersistence<T>
 {
     private static final Logger logger = Logger.getLogger(LdapUserPersistence.class);
-    private Profiler profiler = new Profiler(LdapUserPersistence.class);
 
     public LdapUserPersistence()
     {
@@ -263,6 +262,7 @@ public class LdapUserPersistence<T extends Principal> extends LdapPersistence im
         LdapConnections conns = new LdapConnections(this);
         try
         {
+            Profiler profiler = new Profiler(LdapUserPersistence.class);
             userDAO = new LdapUserDAO<T>(conns);
             profiler.checkpoint("Create LdapUserDAO");
             User<T> user = userDAO.getAugmentedUser(userID);
@@ -476,7 +476,7 @@ public class LdapUserPersistence<T extends Principal> extends LdapPersistence im
     /**
      * Update a user's password. The given user and authenticating user must match.
      *
-     * @param user
+     * @param userID
      * @param oldPassword   current password.
      * @param newPassword   new password.
      * @throws UserNotFoundException If the given user does not exist.
@@ -510,8 +510,7 @@ public class LdapUserPersistence<T extends Principal> extends LdapPersistence im
     /**
      * Reset a user's password. The given user and authenticating user must match.
      *
-     * @param user
-     * @param oldPassword   current password.
+     * @param userID
      * @param newPassword   new password.
      * @throws UserNotFoundException If the given user does not exist.
      * @throws TransientException   If an temporary, unexpected problem occurred.

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/web/UserServlet.java

@@ -177,7 +177,7 @@ public class UserServlet<T extends Principal> extends HttpServlet
             AbstractUserAction action = factory.createAction(request);
             action.setAcceptedContentType(getAcceptedContentType(request));
             log.debug("content-type: " + getAcceptedContentType(request));
-            profiler.checkpoint("created action");
+//            profiler.checkpoint("created action");
 
             // Special case: if the calling subject has a servops X500Principal,
             // AND it is a GET request, do not augment the subject.
@@ -254,6 +254,7 @@ public class UserServlet<T extends Principal> extends HttpServlet
         }
         finally
         {
+            profiler.checkpoint("Action complete");
             logInfo.setElapsedTime(System.currentTimeMillis() - start);
             log.info(logInfo.end());
         }

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/web/groups/ModifyGroupAction.java

@@ -76,6 +76,7 @@ import ca.nrc.cadc.ac.Group;
 import ca.nrc.cadc.ac.User;
 import ca.nrc.cadc.ac.server.GroupPersistence;
 import ca.nrc.cadc.ac.xml.GroupReader;
+import ca.nrc.cadc.profiler.Profiler;
 
 public class ModifyGroupAction extends AbstractGroupAction
 {
@@ -93,10 +94,14 @@ public class ModifyGroupAction extends AbstractGroupAction
 
     public void doAction() throws Exception
     {
+        Profiler profiler = new Profiler(ModifyGroupAction.class);
         GroupReader groupReader = new GroupReader();
         Group group = groupReader.read(this.inputStream);
         Group oldGroup = groupPersistence.getGroup(this.groupName);
+        profiler.checkpoint("get Group");
+
         groupPersistence.modifyGroup(group);
+        profiler.checkpoint("modify Group");
 
         List<String> addedMembers = new ArrayList<String>();
         for (User member : group.getUserMembers())
@@ -131,6 +136,7 @@ public class ModifyGroupAction extends AbstractGroupAction
             deletedMembers = null;
         }
         logGroupInfo(group.getID(), deletedMembers, addedMembers);
+        profiler.checkpoint("log GroupInfo");
 
         syncOut.setHeader("Location", request);
         syncOut.setCode(303);

cadcAccessControl-Server/src/ca/nrc/cadc/ac/server/web/users/AbstractUserAction.java

@@ -101,7 +101,6 @@ public abstract class AbstractUserAction<T extends Principal> implements Privile
     private static final Logger log = Logger.getLogger(AbstractUserAction.class);
     public static final String DEFAULT_CONTENT_TYPE = "text/xml";
     public static final String JSON_CONTENT_TYPE = "application/json";
-    private Profiler profiler = new Profiler(AbstractUserAction.class);
 
     protected boolean isAugmentUser;
     protected UserLogInfo logInfo;
@@ -146,6 +145,7 @@ public abstract class AbstractUserAction<T extends Principal> implements Privile
     {
         try
         {
+            Profiler profiler = new Profiler(AbstractUserAction.class);
             doAction();
             profiler.checkpoint("doAction");
         }
@@ -219,6 +219,7 @@ public abstract class AbstractUserAction<T extends Principal> implements Privile
 
     private void sendError(int responseCode, String message)
     {
+        Profiler profiler = new Profiler(AbstractUserAction.class);
         syncOut.setCode(responseCode);
         syncOut.setHeader("Content-Type", "text/plain");
         if (message != null)
@@ -256,6 +257,7 @@ public abstract class AbstractUserAction<T extends Principal> implements Privile
     protected final UserRequest<Principal> readUserRequest(
             final InputStream inputStream) throws IOException
     {
+        Profiler profiler = new Profiler(AbstractUserAction.class);
         final UserRequest<Principal> userRequest;
 
         if (acceptedContentType.equals(DEFAULT_CONTENT_TYPE))
@@ -289,6 +291,7 @@ public abstract class AbstractUserAction<T extends Principal> implements Privile
     protected final User<Principal> readUser(final InputStream inputStream)
             throws IOException
     {
+        Profiler profiler = new Profiler(AbstractUserAction.class);
         syncOut.setHeader("Content-Type", acceptedContentType);
         final User<Principal> user;
 
@@ -321,6 +324,7 @@ public abstract class AbstractUserAction<T extends Principal> implements Privile
     protected final <T extends Principal> void writeUser(final User<T> user)
             throws IOException
     {
+        Profiler profiler = new Profiler(AbstractUserAction.class);
         syncOut.setHeader("Content-Type", acceptedContentType);
         final Writer writer = syncOut.getWriter();
 
@@ -345,6 +349,7 @@ public abstract class AbstractUserAction<T extends Principal> implements Privile
     protected final <T extends Principal> void writeUsers(final Collection<User<T>> users)
             throws IOException
     {
+        Profiler profiler = new Profiler(AbstractUserAction.class);
         syncOut.setHeader("Content-Type", acceptedContentType);
         final Writer writer = syncOut.getWriter();
 

cadcAccessControl-Server/src/ca/nrc/cadc/auth/AuthenticatorImpl.java

@@ -94,8 +94,6 @@ public class AuthenticatorImpl implements Authenticator
 {
     private static final Logger log = Logger.getLogger(AuthenticatorImpl.class);
 
-    private Profiler profiler = new Profiler(AuthenticatorImpl.class);
-
     public AuthenticatorImpl() { }
 
     /**
@@ -104,6 +102,7 @@ public class AuthenticatorImpl implements Authenticator
      */
     public Subject getSubject(Subject subject)
     {
+        Profiler profiler = new Profiler(AuthenticatorImpl.class);
         log.debug("ac augment subject: " + subject);
         AuthMethod am = AuthenticationUtil.getAuthMethod(subject);
         if (am == null || AuthMethod.ANON.equals(am))
@@ -135,6 +134,7 @@ public class AuthenticatorImpl implements Authenticator
     {
         try
         {
+            Profiler profiler = new Profiler(AuthenticatorImpl.class);
             PluginFactory pluginFactory = new PluginFactory();
             UserPersistence userPersistence = pluginFactory.createUserPersistence();
             User<Principal> user = userPersistence.getAugmentedUser(subject.getPrincipals().iterator().next());