>From 62d8908d91e74320db647b939c0d9900c09d0608 Mon Sep 17 00:00:00 2001
From: Christina Fu <cfu@redhat.com>
Date: Fri, 17 Jun 2016 14:48:17 -0700
Subject: [PATCH] Ticket #2298 Part3- trim down debug log in non-TMS crmf
 enrollments

---
 base/ca/shared/conf/CS.cfg                         |  2 +-
 .../src/com/netscape/kra/EnrollmentService.java    |  3 +-
 .../netscape/cms/profile/common/EnrollProfile.java | 16 +++++++---
 .../com/netscape/cms/servlet/base/CMSServlet.java  |  3 +-
 .../netscape/cms/servlet/cert/CertProcessor.java   | 17 ++++++----
 .../cms/servlet/connector/ConnectorServlet.java    |  5 +--
 .../cms/servlet/processors/CAProcessor.java        | 37 +++++++++++-----------
 .../src/com/netscape/cmscore/apps/CMSEngine.java   |  4 +--
 .../netscape/cmscore/connector/HttpConnection.java |  6 +++-
 .../cmscore/connector/RequestTransfer.java         |  4 +--
 .../com/netscape/cmscore/dbs/DBVirtualList.java    |  6 ++--
 11 files changed, 61 insertions(+), 42 deletions(-)

diff --git a/base/ca/shared/conf/CS.cfg b/base/ca/shared/conf/CS.cfg
index 3634ba5b16ca35b0b1482f6d456bad88e18457e3..8f0fb76081fe1edde26b017910b468d82b870283 100644
--- a/base/ca/shared/conf/CS.cfg
+++ b/base/ca/shared/conf/CS.cfg
@@ -995,7 +995,7 @@ profile.caCMCUserCert.config=[PKI_INSTANCE_PATH]/[PKI_SUBSYSTEM_TYPE]/profiles/c
 profile.caCrossSignedCACert.class_id=caEnrollImpl
 profile.caCrossSignedCACert.config=[PKI_INSTANCE_PATH]/[PKI_SUBSYSTEM_TYPE]/profiles/ca/caCrossSignedCACert.cfg
 profile.caDirBasedDualCert.class_id=caEnrollImpl
-profile.caDirBasedDualCert.config=/var/lib/pki/pki-tomcat/ca/profiles/ca/caDirBasedDualCert.cfg
+profile.caDirBasedDualCert.config=[PKI_INSTANCE_PATH]/[PKI_SUBSYSTEM_TYPE]/profiles/ca/caDirBasedDualCert.cfg
 profile.caDirPinUserCert.class_id=caEnrollImpl
 profile.caDirPinUserCert.config=[PKI_INSTANCE_PATH]/[PKI_SUBSYSTEM_TYPE]/profiles/ca/caDirPinUserCert.cfg
 profile.caDirUserCert.class_id=caEnrollImpl
diff --git a/base/kra/src/com/netscape/kra/EnrollmentService.java b/base/kra/src/com/netscape/kra/EnrollmentService.java
index 35b26a56592cdf0b7b5741f27ad5eb3f83ff01a2..398d1780275f9106271f3c83e958d7e618febaf8 100644
--- a/base/kra/src/com/netscape/kra/EnrollmentService.java
+++ b/base/kra/src/com/netscape/kra/EnrollmentService.java
@@ -175,7 +175,8 @@ public class EnrollmentService implements IService {
 
         String transportCert = request.getExtDataInString(IEnrollProfile.REQUEST_TRANSPORT_CERT);
         if (transportCert != null && transportCert.length() > 0) {
-            CMS.debug("EnrollmentService: serviceRequest: transportCert=" + transportCert);
+            //CMS.debug("EnrollmentService: serviceRequest: transportCert=" + transportCert);
+            CMS.debug("EnrollmentService: serviceRequest: transportCert is in request");
             request.deleteExtData(IEnrollProfile.REQUEST_TRANSPORT_CERT);
         } else {
             CMS.debug("EnrollmentService: serviceRequest: Missing transport certificate");
diff --git a/base/server/cms/src/com/netscape/cms/profile/common/EnrollProfile.java b/base/server/cms/src/com/netscape/cms/profile/common/EnrollProfile.java
index 7d7ce06614d82f2d972c6c83f2e1d0cd11bb1e6b..e828b82f203edfc6e6fb8797c5909c7cdd6a32d9 100644
--- a/base/server/cms/src/com/netscape/cms/profile/common/EnrollProfile.java
+++ b/base/server/cms/src/com/netscape/cms/profile/common/EnrollProfile.java
@@ -378,7 +378,8 @@ public abstract class EnrollProfile extends BasicProfile
             throw new EProfileException(
                     CMS.getUserMessage(locale, "CMS_PROFILE_INVALID_REQUEST"));
         }
-        CMS.debug("EnrollProfile: Start parseCMC(): " + certreq);
+        //CMS.debug("EnrollProfile: Start parseCMC(): " + certreq);
+        CMS.debug("EnrollProfile.parseCMC(): start");
 
         TaggedRequest msgs[] = null;
 
@@ -465,6 +466,7 @@ public abstract class EnrollProfile extends BasicProfile
             } else
                 return null;
 
+            CMS.debug("EnrollProfile.parseCMC: end");
             return msgs;
         } catch (Exception e) {
             CMS.debug("EnrollProfile: Unable to parse CMC request: " + e);
@@ -803,7 +805,7 @@ public abstract class EnrollProfile extends BasicProfile
             throw new EProfileException(
                     CMS.getUserMessage(locale, "CMS_PROFILE_INVALID_REQUEST"));
         }
-        CMS.debug("EnrollProfile: Start parseCRMF(): " + certreq);
+        CMS.debug("EnrollProfile: Start parseCRMF(): "/* + certreq*/);
 
         CertReqMsg msgs[] = null;
         String creq = normalizeCertReq(certreq);
@@ -1342,6 +1344,8 @@ public abstract class EnrollProfile extends BasicProfile
         String auditCertificateSubjectName = ILogger.SIGNED_AUDIT_EMPTY_VALUE;
         String subject = null;
 
+        CMS.debug("EnrollProfile.validate: start");
+
         // try {
         X509CertInfo info = request.getExtDataInCertInfo(REQUEST_CERTINFO);
 
@@ -1357,6 +1361,8 @@ public abstract class EnrollProfile extends BasicProfile
                     // NOTE:  This is ok even if the cert subject name
                     //        is "" (empty)!
                     auditCertificateSubjectName = subject.trim();
+                    CMS.debug("EnrollProfile.validate: cert subject name:" +
+                            auditCertificateSubjectName);
                 }
             }
 
@@ -1413,12 +1419,14 @@ public abstract class EnrollProfile extends BasicProfile
             throw new ERejectException(CMS.getUserMessage(
                         locale, "CMS_PROFILE_EMPTY_KEY"));
         }
-
+        /*
         try {
-            CMS.debug("EnrollProfile certInfo : " + info);
+            CMS.debug("EnrollProfile.validate: certInfo : \n" + info);
         } catch (NullPointerException e) {
             // do nothing
         }
+        */
+        CMS.debug("EnrollProfile.validate: end");
     }
 
     /**
diff --git a/base/server/cms/src/com/netscape/cms/servlet/base/CMSServlet.java b/base/server/cms/src/com/netscape/cms/servlet/base/CMSServlet.java
index 99d18bbcbe1647454f05ba37db76291b5e657289..ab9b9367f637b0b281f6a049e6318708312259f0 100644
--- a/base/server/cms/src/com/netscape/cms/servlet/base/CMSServlet.java
+++ b/base/server/cms/src/com/netscape/cms/servlet/base/CMSServlet.java
@@ -424,7 +424,8 @@ public abstract class CMSServlet extends HttpServlet {
                     pn.equalsIgnoreCase("host_challenge") ||
                     pn.equalsIgnoreCase("card_challenge") ||
                     pn.equalsIgnoreCase("card_cryptogram") ||
-                    pn.equalsIgnoreCase("drm_trans_desKey")) {
+                    pn.equalsIgnoreCase("drm_trans_desKey") ||
+                    pn.equalsIgnoreCase("cert_request")) {
                 CMS.debug("CMSServlet::service() param name='" + pn +
                         "' value='(sensitive)'");
             } else {
diff --git a/base/server/cms/src/com/netscape/cms/servlet/cert/CertProcessor.java b/base/server/cms/src/com/netscape/cms/servlet/cert/CertProcessor.java
index 4395a63edba5ca882c8401cfe55ada93b56af8bd..17b453ab5d82bd7c18612263f01e297a4e9df3da 100644
--- a/base/server/cms/src/com/netscape/cms/servlet/cert/CertProcessor.java
+++ b/base/server/cms/src/com/netscape/cms/servlet/cert/CertProcessor.java
@@ -122,6 +122,7 @@ public class CertProcessor extends CAProcessor {
      * is retrieved from request record
      */
     private void setInputsIntoRequest(IRequest request, IProfile profile, IRequest req, Locale locale) {
+        CMS.debug("CertProcessor: setInputsIntoRequest()");
         // passing inputs into request
         Enumeration<String> inputIds = profile.getProfileInputIds();
 
@@ -134,19 +135,19 @@ public class CertProcessor extends CAProcessor {
                 while (inputNames.hasMoreElements()) {
                     String inputName = inputNames.nextElement();
                     String inputValue = "";
-                    CMS.debug("CertRequestSubmitter: setInputsIntoRequest() getting input name= " + inputName);
+                    //CMS.debug("CertProcessor: setInputsIntoRequest() getting input name= " + inputName);
                     try {
                         inputValue = profileInput.getValue(inputName, locale, request);
                     } catch (Exception e) {
-                        CMS.debug("CertRequestSubmitter: setInputsIntoRequest() getvalue() failed: " + e.toString());
+                        CMS.debug("CertProcessor: setInputsIntoRequest() getvalue() failed: " + e.toString());
                     }
 
                     if (inputValue != null) {
-                        CMS.debug("CertRequestSubmitter: setInputsIntoRequest() setting value in ctx:" + inputValue);
+                        //CMS.debug("CertProcessor: setInputsIntoRequest() setting value in ctx:" + inputValue);
                         req.setExtData(inputName, inputValue);
-                    } else {
-                        CMS.debug("CertRequestSubmitter: setInputsIntoRequest() value null");
-                    }
+                    }/* else {
+                        CMS.debug("CertProcessor: setInputsIntoRequest() value null");
+                    }*/
                 }
             }
         }
@@ -179,7 +180,7 @@ public class CertProcessor extends CAProcessor {
                 // reset the "auditRequesterID"
                 auditRequesterID = auditRequesterID(req);
 
-                // print request debug
+                /* print request debug
                 CMS.debug("CertProcessor: Request:");
                 if (req != null) {
                     Enumeration<String> reqKeys = req.getExtDataKeys();
@@ -191,7 +192,9 @@ public class CertProcessor extends CAProcessor {
                         }
                     }
                 }
+                */
 
+                CMS.debug("CertProcessor.submitRequest: calling profile submit");
                 profile.submit(authToken, req);
                 req.setRequestStatus(RequestStatus.COMPLETE);
 
diff --git a/base/server/cms/src/com/netscape/cms/servlet/connector/ConnectorServlet.java b/base/server/cms/src/com/netscape/cms/servlet/connector/ConnectorServlet.java
index eceab03d159bf264ca8d3a2196404083eac7dd08..582223ecb2c49344d3b03bfb9b7d61f4d12233a9 100644
--- a/base/server/cms/src/com/netscape/cms/servlet/connector/ConnectorServlet.java
+++ b/base/server/cms/src/com/netscape/cms/servlet/connector/ConnectorServlet.java
@@ -618,12 +618,13 @@ public class ConnectorServlet extends CMSServlet {
                 s.put(SessionContext.REQUESTER_ID, msg.getReqId());
             }
 
-            CMS.debug("ConnectorServlet: calling processRequest instance=" +
-                    thisreq);
+            //CMS.debug("ConnectorServlet: calling processRequest instance=" +
+            //        thisreq);
             if (isProfileRequest(thisreq)) {
                 normalizeProfileRequest(thisreq);
             }
 
+            CMS.debug("ConnectorServlet: calling processRequest");
             try {
                 queue.processRequest(thisreq);
 
diff --git a/base/server/cms/src/com/netscape/cms/servlet/processors/CAProcessor.java b/base/server/cms/src/com/netscape/cms/servlet/processors/CAProcessor.java
index e3b3d3497fa63c3986fbb33af77f30aad1e7146d..606b6afaa60c48bb6eec2602b86ae1ed68a22d26 100644
--- a/base/server/cms/src/com/netscape/cms/servlet/processors/CAProcessor.java
+++ b/base/server/cms/src/com/netscape/cms/servlet/processors/CAProcessor.java
@@ -174,12 +174,12 @@ public class CAProcessor extends Processor {
         // authId = cs.getString(AUTH_ID, "").isEmpty() ? null : cs.getString(AUTH_ID);
 
         if (authority == null) {
-            throw new EBaseException("CertProcessor: authority is null");
+            throw new EBaseException("CAProcessor: authority is null");
         }
 
         queue = authority.getRequestQueue();
         if (queue == null) {
-            throw new EBaseException("CertProcessor: cannot get request queue");
+            throw new EBaseException("CAProcessor: cannot get request queue");
         }
 
         if (profileSubId == null || profileSubId.equals("")) {
@@ -188,12 +188,12 @@ public class CAProcessor extends Processor {
 
         ps = (IProfileSubsystem) CMS.getSubsystem(profileSubId);
         if (ps == null) {
-            throw new EBaseException("CertProcessor: Profile Subsystem not found");
+            throw new EBaseException("CAProcessor: Profile Subsystem not found");
         }
 
         certdb = authority.getCertificateRepository();
         if (certdb == null) {
-            throw new EBaseException("CertProcessor: Certificate repository not found");
+            throw new EBaseException("CAProcessor: Certificate repository not found");
         }
     }
 
@@ -289,7 +289,8 @@ public class CAProcessor extends Processor {
                     paramName.equalsIgnoreCase("pin") ||
                     paramName.equalsIgnoreCase("pwd") ||
                     paramName.equalsIgnoreCase("pwdagain") ||
-                    paramName.equalsIgnoreCase("uPasswd")) {
+                    paramName.equalsIgnoreCase("uPasswd") ||
+                    paramName.equalsIgnoreCase("cert_request")) {
                 CMS.debug("CAProcessor: - " + paramName + ": (sensitive)");
             } else {
                 CMS.debug("CAProcessor: - " + paramName + ": " + entry.getValue());
@@ -378,46 +379,46 @@ public class CAProcessor extends Processor {
                 if (sdn != null) {
                     ouid = getUidFromDN(sdn);
                     if (ouid != null)
-                        CMS.debug("CertProcessor: renewal: authToken original uid not found");
+                        CMS.debug("CAProcessor: renewal: authToken original uid not found");
                 }
             } else {
-                CMS.debug("CertProcessor: renewal: authToken original uid found in orig request auth_token");
+                CMS.debug("CAProcessor: renewal: authToken original uid found in orig request auth_token");
             }
             String auid = authToken.getInString("uid");
             if (auid != null) { // not through ssl client auth
-                CMS.debug("CertProcessor: renewal: authToken uid found:" + auid);
+                CMS.debug("CAProcessor: renewal: authToken uid found:" + auid);
                 // authenticated with uid
                 // put "orig_req.auth_token.uid" so that authz with
                 // UserOrigReqAccessEvaluator will work
                 if (ouid != null) {
                     context.put("orig_req.auth_token.uid", ouid);
-                    CMS.debug("CertProcessor: renewal: authToken original uid found:" + ouid);
+                    CMS.debug("CAProcessor: renewal: authToken original uid found:" + ouid);
                 } else {
-                    CMS.debug("CertProcessor: renewal: authToken original uid not found");
+                    CMS.debug("CAProcessor: renewal: authToken original uid not found");
                 }
             } else { // through ssl client auth?
-                CMS.debug("CertProcessor: renewal: authToken uid not found:");
+                CMS.debug("CAProcessor: renewal: authToken uid not found:");
                 // put in orig_req's uid
                 if (ouid != null) {
-                    CMS.debug("CertProcessor: renewal: origReq uid not null:" + ouid + ". Setting authtoken");
+                    CMS.debug("CAProcessor: renewal: origReq uid not null:" + ouid + ". Setting authtoken");
                     authToken.set("uid", ouid);
                     context.put(SessionContext.USER_ID, ouid);
                 } else {
-                    CMS.debug("CertProcessor: renewal: origReq uid not found");
+                    CMS.debug("CAProcessor: renewal: origReq uid not found");
                     //                      throw new EBaseException("origReq uid not found");
                 }
             }
 
             String userdn = origReq.getExtDataInString("auth_token.userdn");
             if (userdn != null) {
-                CMS.debug("CertProcessor: renewal: origReq userdn not null:" + userdn + ". Setting authtoken");
+                CMS.debug("CAProcessor: renewal: origReq userdn not null:" + userdn + ". Setting authtoken");
                 authToken.set("userdn", userdn);
             } else {
-                CMS.debug("CertProcessor: renewal: origReq userdn not found");
+                CMS.debug("CAProcessor: renewal: origReq userdn not found");
                 //                      throw new EBaseException("origReq userdn not found");
             }
         } else {
-            CMS.debug("CertProcessor: renewal: authToken null");
+            CMS.debug("CAProcessor: renewal: authToken null");
         }
         return authToken;
     }
@@ -706,7 +707,7 @@ public class CAProcessor extends Processor {
             String n = t.substring(0, i);
             if (n.equalsIgnoreCase("uid")) {
                 String v = t.substring(i + 1);
-                CMS.debug("CertProcessor:: getUidFromDN(): uid found:" + v);
+                CMS.debug("CAProcessor:: getUidFromDN(): uid found:" + v);
                 return v;
             } else {
                 continue;
@@ -932,7 +933,7 @@ public class CAProcessor extends Processor {
             CMS.debug("CertProcessor authToken not null");
 
             String acl = profile.getAuthzAcl();
-            CMS.debug("CertProcessor: authz using acl: " + acl);
+            CMS.debug("CAProcessor: authz using acl: " + acl);
             if (acl != null && acl.length() > 0) {
                 String resource = profileId + ".authz.acl";
                 authorize(aclMethod, resource, authToken, acl);
diff --git a/base/server/cmscore/src/com/netscape/cmscore/apps/CMSEngine.java b/base/server/cmscore/src/com/netscape/cmscore/apps/CMSEngine.java
index 02cc8ff5314446c8393ceacd21d4bfc28e38d888..c62087e92198d5319d195395a5e2310442780a40 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/apps/CMSEngine.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/apps/CMSEngine.java
@@ -2365,9 +2365,9 @@ public class CMSEngine implements ICMSEngine {
         } catch (Exception e) {
         }
 
-        /* debugSleep: sleep for one minute to check request on ldap*/
+        /* debugSleep: sleep for one minute to check something, e.g. ldap*/
         if (debugSleep == true) {
-            CMS.debug("debugSleep: about to sleep for one minute; check ldap");
+            CMS.debug("debugSleep: about to sleep for one minute; do check now: e.g. ldap, hsm, etc.");
             try {
                 Thread.sleep(60000);
             } catch (InterruptedException e) {
diff --git a/base/server/cmscore/src/com/netscape/cmscore/connector/HttpConnection.java b/base/server/cmscore/src/com/netscape/cmscore/connector/HttpConnection.java
index d016b63351ed6ba8fbecd9857b97230287ea9fd1..fbd32683bfab4d78eddd2b9bd1c3cd9a3e2c5f42 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/connector/HttpConnection.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/connector/HttpConnection.java
@@ -191,7 +191,11 @@ public class HttpConnection implements IHttpConnection {
             Debug.trace(pcontent);
             Debug.trace("-------");
         }
-        CMS.debug("HttpConnection.send response: " + pcontent);
+        //CMS.debug("HttpConnection.send response: " + pcontent);
+        if (pcontent != null && !pcontent.equals(""))
+            CMS.debug("HttpConnection.send response: got content");
+        else
+            CMS.debug("HttpConnection.send response: null or empty content");
 
         try {
             replymsg = (IPKIMessage) mReqEncoder.decode(pcontent);
diff --git a/base/server/cmscore/src/com/netscape/cmscore/connector/RequestTransfer.java b/base/server/cmscore/src/com/netscape/cmscore/connector/RequestTransfer.java
index b3479aea0b24c4bca60146c31e638129b0b59bb4..3bce2c15a657987ac6fbef14027af2c9c319afe9 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/connector/RequestTransfer.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/connector/RequestTransfer.java
@@ -67,7 +67,7 @@ public class RequestTransfer {
     public static String[] getTransferAttributes(IRequest r) {
         if (isProfileRequest(r)) {
             // copy everything in the request
-            CMS.debug("RequestTransfer: profile request " +
+            CMS.debug("RequestTransfer: profile request id = " +
                     r.getRequestId().toString());
             Enumeration<String> e = r.getExtDataKeys();
             Vector<String> v = new Vector<String>();
@@ -83,7 +83,7 @@ public class RequestTransfer {
                     continue;
                 if (k.equals("AUTH_TOKEN"))
                     continue;
-                CMS.debug("RequestTransfer: attribute=" + k);
+                //CMS.debug("RequestTransfer: attribute=" + k);
                 if (k.equals("requestStatus")) {
                     CMS.debug("RequestTransfer : requestStatus=" +
                             r.getExtDataInString("requestStatus"));
diff --git a/base/server/cmscore/src/com/netscape/cmscore/dbs/DBVirtualList.java b/base/server/cmscore/src/com/netscape/cmscore/dbs/DBVirtualList.java
index 38646bbfb93840e10a089c8676f21d163a772f2d..00547b0f972eff91c7169adfae092eb0a05edb77 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/dbs/DBVirtualList.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/dbs/DBVirtualList.java
@@ -337,7 +337,7 @@ public class DBVirtualList<E> implements IDBVirtualList<E> {
      */
     public int getSize() {
 
-        CMS.debug("DBVirtualList.getSize()");
+        //CMS.debug("DBVirtualList.getSize()");
 
         if (!mInitialized) {
 
@@ -669,7 +669,7 @@ public class DBVirtualList<E> implements IDBVirtualList<E> {
             mSize = getSize();
         }
 
-        CMS.debug("DBVirtualList: retrieving entry #" + index);
+        //CMS.debug("DBVirtualList: retrieving entry #" + index);
 
         //System.out.println( "need entry " + index );
         if ((index < 0) || (index >= mSize)) {
@@ -718,7 +718,7 @@ public class DBVirtualList<E> implements IDBVirtualList<E> {
             } else { // handle getting entry in reverse direction
                 int reverse_index = mEntries.size() - mJumpToIndex - 1;
 
-                CMS.debug("reverse direction getting index " + reverse_index);
+                //CMS.debug("reverse direction getting index " + reverse_index);
 
                 if (reverse_index < 0 || reverse_index >= mEntries.size()) {
                     CMS.debug("reverse_index out of range " + reverse_index);
-- 
2.4.3

