Added log messages for pre-op mode.

To help troubleshooting the code has been modified to log more
detailed information in pre-op mode.

https://fedorahosted.org/pki/ticket/1654

13 files changed, 126 insertions, 83 deletions

diff --git a/base/ca/src/com/netscape/ca/CertificateAuthority.java b/base/ca/src/com/netscape/ca/CertificateAuthority.java
index 253c4bb32..8ef6fd4b6 100644
--- a/base/ca/src/com/netscape/ca/CertificateAuthority.java
+++ b/base/ca/src/com/netscape/ca/CertificateAuthority.java
@@ -513,11 +513,14 @@ public class CertificateAuthority
                 initSigUnit(/* retrieveKeys */ true);
                 // init default CA attributes like cert version, validity.
                 initDefCaAttrs();
+
             } catch (EBaseException e) {
-                if (CMS.isPreOpMode())
-                    ;
-                else
+                CMS.debug(e);
+                if (CMS.isPreOpMode()) {
+                    CMS.debug("CertificateAuthority.init(): Swallow exception in pre-op mode");
+                } else {
                     throw e;
+                }
             }
 
             mUseNonces = mConfig.getBoolean("enableNonces", true);
@@ -526,8 +529,10 @@ public class CertificateAuthority
             // init request queue and related modules.
             CMS.debug("CertificateAuthority init: initRequestQueue");
             initRequestQueue();
-            if (CMS.isPreOpMode())
+            if (CMS.isPreOpMode()) {
+                CMS.debug("CertificateAuthority.init(): Abort in pre-op mode");
                 return;
+            }
 
             /* The host CA owns these resources so skip these
              * steps for lightweight CAs.
@@ -587,10 +592,12 @@ public class CertificateAuthority
                 CMS.debug("CertificateAuthority: finished init of host authority");
             }
         } catch (EBaseException e) {
-            if (CMS.isPreOpMode())
+            CMS.debug(e);
+            if (CMS.isPreOpMode()) {
+                CMS.debug("CertificateAuthority.init(): Swallow exception in pre-op mode");
                 return;
-            else
-                throw e;
+            }
+            throw e;
         }
     }
 
@@ -758,6 +765,7 @@ public class CertificateAuthority
      */
     public void startup() throws EBaseException {
         if (CMS.isPreOpMode()) {
+            CMS.debug("CertificateAuthority.startup(): Do not start CA in pre-op mode");
             return;
         }
         mService.startup();
diff --git a/base/ocsp/src/com/netscape/ocsp/OCSPAuthority.java b/base/ocsp/src/com/netscape/ocsp/OCSPAuthority.java
index 4a40e89fb..09b85b4d1 100644
--- a/base/ocsp/src/com/netscape/ocsp/OCSPAuthority.java
+++ b/base/ocsp/src/com/netscape/ocsp/OCSPAuthority.java
@@ -27,14 +27,6 @@ import java.security.cert.CertificateParsingException;
 import java.util.Enumeration;
 import java.util.Hashtable;
 
-import netscape.security.util.DerOutputStream;
-import netscape.security.util.DerValue;
-import netscape.security.x509.AlgorithmId;
-import netscape.security.x509.CertificateChain;
-import netscape.security.x509.X500Name;
-import netscape.security.x509.X509CertImpl;
-import netscape.security.x509.X509Key;
-
 import org.mozilla.jss.CryptoManager;
 import org.mozilla.jss.asn1.ASN1Util;
 import org.mozilla.jss.asn1.InvalidBERException;
@@ -65,6 +57,14 @@ import com.netscape.cmsutil.ocsp.OCSPResponse;
 import com.netscape.cmsutil.ocsp.ResponderID;
 import com.netscape.cmsutil.ocsp.ResponseData;
 
+import netscape.security.util.DerOutputStream;
+import netscape.security.util.DerValue;
+import netscape.security.x509.AlgorithmId;
+import netscape.security.x509.CertificateChain;
+import netscape.security.x509.X500Name;
+import netscape.security.x509.X509CertImpl;
+import netscape.security.x509.X509Key;
+
 /**
  * A class represents a Certificate Authority that is
  * responsible for certificate specific operations.
@@ -157,11 +157,14 @@ public class OCSPAuthority implements IOCSPAuthority, IOCSPService, ISubsystem,
             } catch (IllegalAccessException e) {
                 log(ILogger.LL_FAILURE, CMS.getLogMessage("CMSCORE_OCSP_SIGNING_UNIT", e.toString()));
             }
-        } catch (EBaseException ee) {
-            if (CMS.isPreOpMode())
+
+        } catch (EBaseException e) {
+            CMS.debug(e);
+            if (CMS.isPreOpMode()) {
+                CMS.debug("OCSPAuthority.init(): Swallow exception in pre-op mode");
                 return;
-            else
-                throw ee;
+            }
+            throw e;
         }
     }
 
@@ -320,12 +323,17 @@ public class OCSPAuthority implements IOCSPAuthority, IOCSPService, ISubsystem,
         try {
             if (mDefStore != null)
                 mDefStore.startup();
+
         } catch (EBaseException e) {
+            CMS.debug(e);
             if (CMS.isPreOpMode()) {
+                CMS.debug("OCSPAuthority.init(): Swallow exception in pre-op mode");
                 return;
-            } else
-                throw e;
+            }
+            throw e;
+
         } catch (Exception e) {
+            CMS.debug(e);
         }
     }
 
diff --git a/base/server/cms/src/com/netscape/cms/authorization/DirAclAuthz.java b/base/server/cms/src/com/netscape/cms/authorization/DirAclAuthz.java
index bdf3f5e9c..4f14f4c40 100644
--- a/base/server/cms/src/com/netscape/cms/authorization/DirAclAuthz.java
+++ b/base/server/cms/src/com/netscape/cms/authorization/DirAclAuthz.java
@@ -19,15 +19,6 @@ package com.netscape.cms.authorization;
 
 import java.util.Enumeration;
 
-import netscape.ldap.LDAPAttribute;
-import netscape.ldap.LDAPConnection;
-import netscape.ldap.LDAPEntry;
-import netscape.ldap.LDAPException;
-import netscape.ldap.LDAPModification;
-import netscape.ldap.LDAPModificationSet;
-import netscape.ldap.LDAPSearchResults;
-import netscape.ldap.LDAPv2;
-
 import com.netscape.certsrv.acls.ACL;
 import com.netscape.certsrv.acls.EACLsException;
 import com.netscape.certsrv.apps.CMS;
@@ -43,6 +34,15 @@ import com.netscape.certsrv.ldap.ELdapException;
 import com.netscape.certsrv.ldap.ILdapConnFactory;
 import com.netscape.certsrv.logging.ILogger;
 
+import netscape.ldap.LDAPAttribute;
+import netscape.ldap.LDAPConnection;
+import netscape.ldap.LDAPEntry;
+import netscape.ldap.LDAPException;
+import netscape.ldap.LDAPModification;
+import netscape.ldap.LDAPModificationSet;
+import netscape.ldap.LDAPSearchResults;
+import netscape.ldap.LDAPv2;
+
 /**
  * A class for ldap acls based authorization manager
  * The ldap server used for acls is the cms internal ldap db.
@@ -139,8 +139,11 @@ public class DirAclAuthz extends AAclAuthz
             @SuppressWarnings("unused")
             String hostname = ldapConfig.getString("ldapconn.host"); // check for errors
         } catch (EBaseException e) {
-            if (CMS.isPreOpMode())
+            CMS.debug(e);
+            if (CMS.isPreOpMode()) {
+                CMS.debug("DirAclAuthz.init(): Swallow exception in pre-op mode");
                 return;
+            }
         }
 
         mLdapConnFactory = CMS.getLdapBoundConnFactory("DirAclAuthz");
diff --git a/base/server/cms/src/com/netscape/cms/policy/constraints/SubCANameConstraints.java b/base/server/cms/src/com/netscape/cms/policy/constraints/SubCANameConstraints.java
index 07cc3b956..bc41d1bcb 100644
--- a/base/server/cms/src/com/netscape/cms/policy/constraints/SubCANameConstraints.java
+++ b/base/server/cms/src/com/netscape/cms/policy/constraints/SubCANameConstraints.java
@@ -20,11 +20,6 @@ package com.netscape.cms.policy.constraints;
 import java.util.Locale;
 import java.util.Vector;
 
-import netscape.security.x509.CertificateSubjectName;
-import netscape.security.x509.X500Name;
-import netscape.security.x509.X509CertImpl;
-import netscape.security.x509.X509CertInfo;
-
 import com.netscape.certsrv.apps.CMS;
 import com.netscape.certsrv.authority.ICertAuthority;
 import com.netscape.certsrv.base.EBaseException;
@@ -40,6 +35,11 @@ import com.netscape.certsrv.request.PolicyResult;
 import com.netscape.certsrv.security.ISigningUnit;
 import com.netscape.cms.policy.APolicyRule;
 
+import netscape.security.x509.CertificateSubjectName;
+import netscape.security.x509.X500Name;
+import netscape.security.x509.X509CertImpl;
+import netscape.security.x509.X509CertInfo;
+
 /**
  * This simple policy checks the subordinate CA CSR to see
  * if it is the same as the local CA.
@@ -104,6 +104,7 @@ public class SubCANameConstraints extends APolicyRule implements IEnrollmentPoli
         mCA = (ICertificateAuthority) certAuthority;
         ISigningUnit su = mCA.getSigningUnit();
         if (su == null || CMS.isPreOpMode()) {
+            CMS.debug("SubCANameConstraints.init(): Abort due to missing signing unit or in pre-op mode");
             return;
         }
 
diff --git a/base/server/cms/src/com/netscape/cms/policy/extensions/AuthorityKeyIdentifierExt.java b/base/server/cms/src/com/netscape/cms/policy/extensions/AuthorityKeyIdentifierExt.java
index d7e058bf8..1a2220239 100644
--- a/base/server/cms/src/com/netscape/cms/policy/extensions/AuthorityKeyIdentifierExt.java
+++ b/base/server/cms/src/com/netscape/cms/policy/extensions/AuthorityKeyIdentifierExt.java
@@ -22,14 +22,6 @@ import java.security.cert.CertificateException;
 import java.util.Locale;
 import java.util.Vector;
 
-import netscape.security.x509.AuthorityKeyIdentifierExtension;
-import netscape.security.x509.CertificateExtensions;
-import netscape.security.x509.CertificateVersion;
-import netscape.security.x509.KeyIdentifier;
-import netscape.security.x509.SubjectKeyIdentifierExtension;
-import netscape.security.x509.X509CertImpl;
-import netscape.security.x509.X509CertInfo;
-
 import com.netscape.certsrv.apps.CMS;
 import com.netscape.certsrv.authority.ICertAuthority;
 import com.netscape.certsrv.base.EBaseException;
@@ -44,6 +36,14 @@ import com.netscape.certsrv.request.IRequest;
 import com.netscape.certsrv.request.PolicyResult;
 import com.netscape.cms.policy.APolicyRule;
 
+import netscape.security.x509.AuthorityKeyIdentifierExtension;
+import netscape.security.x509.CertificateExtensions;
+import netscape.security.x509.CertificateVersion;
+import netscape.security.x509.KeyIdentifier;
+import netscape.security.x509.SubjectKeyIdentifierExtension;
+import netscape.security.x509.X509CertImpl;
+import netscape.security.x509.X509CertInfo;
+
 /**
  * Authority Public Key Extension Policy
  * Adds the subject public key id extension to certificates.
@@ -163,6 +163,7 @@ public class AuthorityKeyIdentifierExt extends APolicyRule
         //X509Certificate caCert = caChain.getFirstCertificate();
         X509CertImpl caCert = certAuthority.getCACert();
         if (caCert == null || CMS.isPreOpMode()) {
+            CMS.debug("AuthorityKeyIdentifierExt.init(): Abort due to missing CA certificate or in pre-op-mode");
             return;
         }
         KeyIdentifier keyId = formKeyIdentifier(caCert);
diff --git a/base/server/cms/src/com/netscape/cms/policy/extensions/BasicConstraintsExt.java b/base/server/cms/src/com/netscape/cms/policy/extensions/BasicConstraintsExt.java
index eeee26994..5c05d86d9 100644
--- a/base/server/cms/src/com/netscape/cms/policy/extensions/BasicConstraintsExt.java
+++ b/base/server/cms/src/com/netscape/cms/policy/extensions/BasicConstraintsExt.java
@@ -23,12 +23,6 @@ import java.security.cert.X509Certificate;
 import java.util.Locale;
 import java.util.Vector;
 
-import netscape.security.x509.BasicConstraintsExtension;
-import netscape.security.x509.CertificateChain;
-import netscape.security.x509.CertificateExtensions;
-import netscape.security.x509.CertificateVersion;
-import netscape.security.x509.X509CertInfo;
-
 import com.netscape.certsrv.apps.CMS;
 import com.netscape.certsrv.authority.ICertAuthority;
 import com.netscape.certsrv.base.EBaseException;
@@ -46,6 +40,12 @@ import com.netscape.certsrv.request.IRequest;
 import com.netscape.certsrv.request.PolicyResult;
 import com.netscape.cms.policy.APolicyRule;
 
+import netscape.security.x509.BasicConstraintsExtension;
+import netscape.security.x509.CertificateChain;
+import netscape.security.x509.CertificateExtensions;
+import netscape.security.x509.CertificateVersion;
+import netscape.security.x509.X509CertInfo;
+
 /**
  * Basic Constraints policy.
  * Adds the Basic constraints extension.
@@ -121,6 +121,7 @@ public class BasicConstraintsExt extends APolicyRule
         } else {
             CertificateChain caChain = certAuthority.getCACertChain();
             if (caChain == null || CMS.isPreOpMode()) {
+                CMS.debug("BasicConstraintsExt.init(): Abort due to missing CA certificate chain or in pre-op-mode");
                 return;
             }
             X509Certificate caCert = caChain.getFirstCertificate();
diff --git a/base/server/cmscore/src/com/netscape/cmscore/authentication/AuthSubsystem.java b/base/server/cmscore/src/com/netscape/cmscore/authentication/AuthSubsystem.java
index 8e2c59c26..bb42f5f4d 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/authentication/AuthSubsystem.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/authentication/AuthSubsystem.java
@@ -258,10 +258,14 @@ public class AuthSubsystem implements IAuthSubsystem {
                 }
             }
             log(ILogger.LL_INFO, CMS.getLogMessage("INIT_DONE", getId()));
-        } catch (EBaseException ee) {
-            if (CMS.isPreOpMode())
+
+        } catch (EBaseException e) {
+            CMS.debug(e);
+            if (CMS.isPreOpMode()) {
+                CMS.debug("AuthSubsystem.init(): Swallow exception in pre-op mode");
                 return;
-            throw ee;
+            }
+            throw e;
         }
     }
 
diff --git a/base/server/cmscore/src/com/netscape/cmscore/authentication/PasswdUserDBAuthentication.java b/base/server/cmscore/src/com/netscape/cmscore/authentication/PasswdUserDBAuthentication.java
index 07092aa07..908df691e 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/authentication/PasswdUserDBAuthentication.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/authentication/PasswdUserDBAuthentication.java
@@ -84,8 +84,10 @@ public class PasswdUserDBAuthentication implements IAuthManager, IPasswdUserDBAu
         /* internal database directory used */
         DBSubsystem dbs = (DBSubsystem) DBSubsystem.getInstance();
         LdapConnInfo ldapinfo = dbs.getLdapConnInfo();
-        if (ldapinfo == null && CMS.isPreOpMode())
+        if (ldapinfo == null && CMS.isPreOpMode()) {
+            CMS.debug("PasswdUserDBAuthentication.init(): Abort due to missing LDAP connection info in pre-op mode");
             return;
+        }
 
         mAnonConnFactory = new LdapAnonConnFactory("PasswdUserDBAuthentication", 3, 20, ldapinfo);
 
diff --git a/base/server/cmscore/src/com/netscape/cmscore/authorization/AuthzSubsystem.java b/base/server/cmscore/src/com/netscape/cmscore/authorization/AuthzSubsystem.java
index 70dad2040..31d5e71b4 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/authorization/AuthzSubsystem.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/authorization/AuthzSubsystem.java
@@ -177,10 +177,14 @@ public class AuthzSubsystem implements IAuthzSubsystem {
                     Debug.trace("loaded authz instance " + insName + " impl " + implName);
                 }
             }
-        } catch (EBaseException ee) {
-            if (CMS.isPreOpMode())
+
+        } catch (EBaseException e) {
+            CMS.debug(e);
+            if (CMS.isPreOpMode()) {
+                CMS.debug("AuthzSubsystem.init(): Swallow exception in pre-op mode");
                 return;
-            throw ee;
+            }
+            throw e;
         }
 
         log(ILogger.LL_INFO, CMS.getLogMessage("INIT_DONE", getId()));
diff --git a/base/server/cmscore/src/com/netscape/cmscore/cert/CrossCertPairSubsystem.java b/base/server/cmscore/src/com/netscape/cmscore/cert/CrossCertPairSubsystem.java
index 29ec0f54f..7f30c8458 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/cert/CrossCertPairSubsystem.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/cert/CrossCertPairSubsystem.java
@@ -25,15 +25,6 @@ import java.security.cert.CertificateFactory;
 import java.security.cert.X509Certificate;
 import java.util.Enumeration;
 
-import netscape.ldap.LDAPAttribute;
-import netscape.ldap.LDAPConnection;
-import netscape.ldap.LDAPEntry;
-import netscape.ldap.LDAPException;
-import netscape.ldap.LDAPModification;
-import netscape.ldap.LDAPModificationSet;
-import netscape.ldap.LDAPSearchResults;
-import netscape.ldap.LDAPv2;
-
 import com.netscape.certsrv.apps.CMS;
 import com.netscape.certsrv.base.EBaseException;
 import com.netscape.certsrv.base.IConfigStore;
@@ -46,6 +37,15 @@ import com.netscape.certsrv.publish.IPublisherProcessor;
 import com.netscape.certsrv.publish.IXcertPublisherProcessor;
 import com.netscape.cmscore.ldapconn.LdapBoundConnFactory;
 
+import netscape.ldap.LDAPAttribute;
+import netscape.ldap.LDAPConnection;
+import netscape.ldap.LDAPEntry;
+import netscape.ldap.LDAPException;
+import netscape.ldap.LDAPModification;
+import netscape.ldap.LDAPModificationSet;
+import netscape.ldap.LDAPSearchResults;
+import netscape.ldap.LDAPv2;
+
 /**
  * Subsystem for handling cross certificate pairing and publishing
  * Intended use:
@@ -128,9 +128,13 @@ public class CrossCertPairSubsystem implements ICrossCertPairSubsystem {
                                 PROP_LDAP));
                 return;
             }
+
         } catch (EBaseException e) {
-            if (CMS.isPreOpMode())
+            CMS.debug(e);
+            if (CMS.isPreOpMode()) {
+                CMS.debug("CrossCertPairSubsystem.init(): Swallow exception in pre-op mode");
                 return;
+            }
             throw e;
         }
     }
diff --git a/base/server/cmscore/src/com/netscape/cmscore/dbs/DBSubsystem.java b/base/server/cmscore/src/com/netscape/cmscore/dbs/DBSubsystem.java
index 2de9945f7..50c07af25 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/dbs/DBSubsystem.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/dbs/DBSubsystem.java
@@ -20,19 +20,6 @@ package com.netscape.cmscore.dbs;
 import java.math.BigInteger;
 import java.util.Hashtable;
 
-import netscape.ldap.LDAPAttribute;
-import netscape.ldap.LDAPAttributeSchema;
-import netscape.ldap.LDAPAttributeSet;
-import netscape.ldap.LDAPConnection;
-import netscape.ldap.LDAPEntry;
-import netscape.ldap.LDAPException;
-import netscape.ldap.LDAPModification;
-import netscape.ldap.LDAPObjectClassSchema;
-import netscape.ldap.LDAPSchema;
-import netscape.ldap.LDAPSearchResults;
-import netscape.ldap.LDAPv3;
-import netscape.security.x509.CertificateValidity;
-
 import com.netscape.certsrv.apps.CMS;
 import com.netscape.certsrv.base.EBaseException;
 import com.netscape.certsrv.base.EPropertyNotDefined;
@@ -53,6 +40,19 @@ import com.netscape.cmscore.ldapconn.LdapAuthInfo;
 import com.netscape.cmscore.ldapconn.LdapBoundConnFactory;
 import com.netscape.cmscore.ldapconn.LdapConnInfo;
 
+import netscape.ldap.LDAPAttribute;
+import netscape.ldap.LDAPAttributeSchema;
+import netscape.ldap.LDAPAttributeSet;
+import netscape.ldap.LDAPConnection;
+import netscape.ldap.LDAPEntry;
+import netscape.ldap.LDAPException;
+import netscape.ldap.LDAPModification;
+import netscape.ldap.LDAPObjectClassSchema;
+import netscape.ldap.LDAPSchema;
+import netscape.ldap.LDAPSearchResults;
+import netscape.ldap.LDAPv3;
+import netscape.security.x509.CertificateValidity;
+
 /**
  * A class represents the database subsystem that manages
  * the backend data storage.
@@ -640,10 +640,13 @@ public class DBSubsystem implements IDBSubsystem {
             tmpConfig = (IConfigStore) (((PropConfigStore) mConfig).clone());
 
             tmpConfig.putString(PROP_BASEDN, mBaseDN);
+
         } catch (EBaseException e) {
             CMS.debug(e);
-            if (CMS.isPreOpMode())
+            if (CMS.isPreOpMode()) {
+                CMS.debug("DBSubsystem.init(): Swallow exception in pre-op mode");
                 return;
+            }
             throw e;
         }
 
diff --git a/base/server/cmscore/src/com/netscape/cmscore/selftests/SelfTestSubsystem.java b/base/server/cmscore/src/com/netscape/cmscore/selftests/SelfTestSubsystem.java
index 4b89aa49e..ff938dd7b 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/selftests/SelfTestSubsystem.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/selftests/SelfTestSubsystem.java
@@ -1793,7 +1793,7 @@ public class SelfTestSubsystem
         }
 
         if (CMS.isPreOpMode()) {
-            // do not run selftests in pre-op mode
+            CMS.debug("SelfTestSubsystem.startup(): Do not run selftests in pre-op mode");
             return;
         }
 
diff --git a/base/server/cmscore/src/com/netscape/cmscore/usrgrp/UGSubsystem.java b/base/server/cmscore/src/com/netscape/cmscore/usrgrp/UGSubsystem.java
index a11c551e5..910c58697 100644
--- a/base/server/cmscore/src/com/netscape/cmscore/usrgrp/UGSubsystem.java
+++ b/base/server/cmscore/src/com/netscape/cmscore/usrgrp/UGSubsystem.java
@@ -139,9 +139,13 @@ public final class UGSubsystem implements IUGSubsystem {
 
             mLdapConnFactory = new LdapBoundConnFactory("UGSubsystem");
             mLdapConnFactory.init(ldapConfig);
+
         } catch (EBaseException e) {
-            if (CMS.isPreOpMode())
+            CMS.debug(e);
+            if (CMS.isPreOpMode()) {
+                CMS.debug("UGSubsystem.init(): Swallow exception in pre-op mode");
                 return;
+            }
             throw e;
         }
     }