From 5831058e13446fab98d67be27a5d47fe57eef6f7 Mon Sep 17 00:00:00 2001
From: Christina Fu <cfu@redhat.com>
Date: Fri, 8 May 2015 10:27:37 -0700
Subject: [PATCH] Ticket 1160 audit needed for getKeyInfo; audit missing for
 auth/authz at REST    *addresses: audit needed for getKeyInfo

---
 base/kra/shared/conf/CS.cfg.in                     |   4 +-
 .../org/dogtagpki/server/kra/rest/KeyService.java  | 170 ++++++++++++++++-----
 2 files changed, 131 insertions(+), 43 deletions(-)

diff --git a/base/kra/shared/conf/CS.cfg.in b/base/kra/shared/conf/CS.cfg.in
index 7ecacf64dacae14ea86ec7b32328b555e2c27aeb..c487868e7decd4919be77f9593d0ac7f14dc174c 100644
--- a/base/kra/shared/conf/CS.cfg.in
+++ b/base/kra/shared/conf/CS.cfg.in
@@ -279,11 +279,11 @@ log.instance.SignedAudit._001=## Signed Audit Logging
 log.instance.SignedAudit._002=##
 log.instance.SignedAudit._003=##
 log.instance.SignedAudit._004=## Available Audit events:
-log.instance.SignedAudit._005=## AUDIT_LOG_STARTUP,AUDIT_LOG_SHUTDOWN,ROLE_ASSUME,CONFIG_CERT_POLICY,CONFIG_CERT_PROFILE,CONFIG_CRL_PROFILE,CONFIG_OCSP_PROFILE,CONFIG_AUTH,CONFIG_ROLE,CONFIG_ACL,CONFIG_SIGNED_AUDIT,CONFIG_ENCRYPTION,CONFIG_TRUSTED_PUBLIC_KEY,CONFIG_DRM,SELFTESTS_EXECUTION,AUDIT_LOG_DELETE,LOG_PATH_CHANGE,LOG_EXPIRATION_CHANGE,PRIVATE_KEY_ARCHIVE_REQUEST,PRIVATE_KEY_ARCHIVE_REQUEST_PROCESSED,PRIVATE_KEY_EXPORT_REQUEST_PROCESSED_SUCCESS,PRIVATE_KEY_EXPORT_REQUEST_PROCESSED_FAILURE,KEY_RECOVERY_REQUEST,KEY_RECOVERY_REQUEST_ASYNC,KEY_RECOVERY_AGENT_LOGIN,KEY_RECOVERY_REQUEST_PROCESSED,KEY_RECOVERY_REQUEST_PROCESSED_ASYNC,KEY_GEN_ASYMMETRIC,NON_PROFILE_CERT_REQUEST,PROFILE_CERT_REQUEST,CERT_REQUEST_PROCESSED,CERT_STATUS_CHANGE_REQUEST,CERT_STATUS_CHANGE_REQUEST_PROCESSED,AUTHZ_SUCCESS,AUTHZ_FAIL,INTER_BOUNDARY,AUTH_FAIL,AUTH_SUCCESS,CERT_PROFILE_APPROVAL,PROOF_OF_POSSESSION,CRL_RETRIEVAL,CRL_VALIDATION,CMC_SIGNED_REQUEST_SIG_VERIFY,SERVER_SIDE_KEYGEN_REQUEST_PROCESSED_FAILURE,SERVER_SIDE_KEYGEN_REQUEST_PROCESSED_SUCCESS,SERVER_SIDE_KEYGEN_REQUEST,COMPUTE_SESSION_KEY_REQUEST,COMPUTE_SESSION_KEY_REQUEST_PROCESSED_SUCCESS, COMPUTE_SESSION_KEY_REQUEST_PROCESSED_FAILURE,DIVERSIFY_KEY_REQUEST,DIVERSIFY_KEY_REQUEST_PROCESSED_SUCCESS, DIVERSIFY_KEY_REQUEST_PROCESSED_FAILURE,ENCRYPT_DATA_REQUEST,ENCRYPT_DATA_REQUEST_PROCESSED_SUCCESS,ENCRYPT_DATA_REQUEST_PROCESSED_FAILURE,OCSP_ADD_CA_REQUEST,OCSP_ADD_CA_REQUEST_PROCESSED,OCSP_REMOVE_CA_REQUEST,OCSP_REMOVE_CA_REQUEST_PROCESSED_SUCCESS,OCSP_REMOVE_CA_REQUEST_PROCESSED_FAILURE,COMPUTE_RANDOM_DATA_REQUEST,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_SUCCESS,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_FAILURE,CIMC_CERT_VERIFICATION,CONFIG_SERIAL_NUMBER,SECURITY_DATA_ARCHIVAL_REQUEST,SECURITY_DATA_ARCHIVAL_REQUEST_PROCESSED,SECURITY_DATA_RECOVERY_REQUEST,SECURITY_DATA_RECOVERY_REQUEST_PROCESSED,SECURITY_DATA_RECOVERY_REQUEST_STATE_CHANGE,SECURITY_DATA_RETRIEVE_KEY,SYMKEY_GENERATION_REQUEST,SYMKEY_GENERATION_REQUEST_PROCESSED,ASYMKEY_GENERATION_REQUEST
+log.instance.SignedAudit._005=## AUDIT_LOG_STARTUP,AUDIT_LOG_SHUTDOWN,ROLE_ASSUME,CONFIG_CERT_POLICY,CONFIG_CERT_PROFILE,CONFIG_CRL_PROFILE,CONFIG_OCSP_PROFILE,CONFIG_AUTH,CONFIG_ROLE,CONFIG_ACL,CONFIG_SIGNED_AUDIT,CONFIG_ENCRYPTION,CONFIG_TRUSTED_PUBLIC_KEY,CONFIG_DRM,SELFTESTS_EXECUTION,AUDIT_LOG_DELETE,LOG_PATH_CHANGE,LOG_EXPIRATION_CHANGE,PRIVATE_KEY_ARCHIVE_REQUEST,PRIVATE_KEY_ARCHIVE_REQUEST_PROCESSED,PRIVATE_KEY_EXPORT_REQUEST_PROCESSED_SUCCESS,PRIVATE_KEY_EXPORT_REQUEST_PROCESSED_FAILURE,KEY_RECOVERY_REQUEST,KEY_RECOVERY_REQUEST_ASYNC,KEY_RECOVERY_AGENT_LOGIN,KEY_RECOVERY_REQUEST_PROCESSED,KEY_RECOVERY_REQUEST_PROCESSED_ASYNC,KEY_GEN_ASYMMETRIC,NON_PROFILE_CERT_REQUEST,PROFILE_CERT_REQUEST,CERT_REQUEST_PROCESSED,CERT_STATUS_CHANGE_REQUEST,CERT_STATUS_CHANGE_REQUEST_PROCESSED,AUTHZ_SUCCESS,AUTHZ_FAIL,INTER_BOUNDARY,AUTH_FAIL,AUTH_SUCCESS,CERT_PROFILE_APPROVAL,PROOF_OF_POSSESSION,CRL_RETRIEVAL,CRL_VALIDATION,CMC_SIGNED_REQUEST_SIG_VERIFY,SERVER_SIDE_KEYGEN_REQUEST_PROCESSED_FAILURE,SERVER_SIDE_KEYGEN_REQUEST_PROCESSED_SUCCESS,SERVER_SIDE_KEYGEN_REQUEST,COMPUTE_SESSION_KEY_REQUEST,COMPUTE_SESSION_KEY_REQUEST_PROCESSED_SUCCESS, COMPUTE_SESSION_KEY_REQUEST_PROCESSED_FAILURE,DIVERSIFY_KEY_REQUEST,DIVERSIFY_KEY_REQUEST_PROCESSED_SUCCESS, DIVERSIFY_KEY_REQUEST_PROCESSED_FAILURE,ENCRYPT_DATA_REQUEST,ENCRYPT_DATA_REQUEST_PROCESSED_SUCCESS,ENCRYPT_DATA_REQUEST_PROCESSED_FAILURE,OCSP_ADD_CA_REQUEST,OCSP_ADD_CA_REQUEST_PROCESSED,OCSP_REMOVE_CA_REQUEST,OCSP_REMOVE_CA_REQUEST_PROCESSED_SUCCESS,OCSP_REMOVE_CA_REQUEST_PROCESSED_FAILURE,COMPUTE_RANDOM_DATA_REQUEST,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_SUCCESS,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_FAILURE,CIMC_CERT_VERIFICATION,CONFIG_SERIAL_NUMBER,SECURITY_DATA_ARCHIVAL_REQUEST,SECURITY_DATA_ARCHIVAL_REQUEST_PROCESSED,SECURITY_DATA_RECOVERY_REQUEST,SECURITY_DATA_RECOVERY_REQUEST_PROCESSED,SECURITY_DATA_RECOVERY_REQUEST_STATE_CHANGE,SECURITY_DATA_RETRIEVE_KEY,SYMKEY_GENERATION_REQUEST,SYMKEY_GENERATION_REQUEST_PROCESSED,ASYMKEY_GENERATION_REQUEST,SECURITY_DATA_RETRIEVE_KEY
 log.instance.SignedAudit._006=##
 log.instance.SignedAudit.bufferSize=512
 log.instance.SignedAudit.enable=true
-log.instance.SignedAudit.events=AUDIT_LOG_STARTUP,AUDIT_LOG_SHUTDOWN,ROLE_ASSUME,CONFIG_CERT_POLICY,CONFIG_CERT_PROFILE,CONFIG_CRL_PROFILE,CONFIG_OCSP_PROFILE,CONFIG_AUTH,CONFIG_ROLE,CONFIG_ACL,CONFIG_SIGNED_AUDIT,CONFIG_ENCRYPTION,CONFIG_TRUSTED_PUBLIC_KEY,CONFIG_DRM,SELFTESTS_EXECUTION,AUDIT_LOG_DELETE,LOG_PATH_CHANGE,PRIVATE_KEY_ARCHIVE_REQUEST,PRIVATE_KEY_ARCHIVE_REQUEST_PROCESSED,PRIVATE_KEY_EXPORT_REQUEST_PROCESSED_SUCCESS,PRIVATE_KEY_EXPORT_REQUEST_PROCESSED_FAILURE,KEY_RECOVERY_REQUEST,KEY_RECOVERY_REQUEST_ASYNC,KEY_RECOVERY_AGENT_LOGIN,KEY_RECOVERY_REQUEST_PROCESSED,KEY_RECOVERY_REQUEST_PROCESSED_ASYNC,KEY_GEN_ASYMMETRIC,NON_PROFILE_CERT_REQUEST,PROFILE_CERT_REQUEST,CERT_REQUEST_PROCESSED,CERT_STATUS_CHANGE_REQUEST,CERT_STATUS_CHANGE_REQUEST_PROCESSED,AUTHZ_SUCCESS,AUTHZ_FAIL,INTER_BOUNDARY,AUTH_FAIL,AUTH_SUCCESS,CERT_PROFILE_APPROVAL,PROOF_OF_POSSESSION,CRL_RETRIEVAL,CRL_VALIDATION,CMC_SIGNED_REQUEST_SIG_VERIFY,SERVER_SIDE_KEYGEN_REQUEST_PROCESSED_FAILURE,SERVER_SIDE_KEYGEN_REQUEST_PROCESSED_SUCCESS,SERVER_SIDE_KEYGEN_REQUEST,COMPUTE_SESSION_KEY_REQUEST,COMPUTE_SESSION_KEY_REQUEST_PROCESSED_SUCCESS, COMPUTE_SESSION_KEY_REQUEST_PROCESSED_FAILURE,DIVERSIFY_KEY_REQUEST,DIVERSIFY_KEY_REQUEST_PROCESSED_SUCCESS, DIVERSIFY_KEY_REQUEST_PROCESSED_FAILURE,ENCRYPT_DATA_REQUEST,ENCRYPT_DATA_REQUEST_PROCESSED_SUCCESS,ENCRYPT_DATA_REQUEST_PROCESSED_FAILURE,OCSP_ADD_CA_REQUEST,OCSP_ADD_CA_REQUEST_PROCESSED,OCSP_REMOVE_CA_REQUEST,OCSP_REMOVE_CA_REQUEST_PROCESSED_SUCCESS,OCSP_REMOVE_CA_REQUEST_PROCESSED_FAILURE,COMPUTE_RANDOM_DATA_REQUEST,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_SUCCESS,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_FAILURE,CIMC_CERT_VERIFICATION,CONFIG_SERIAL_NUMBER,SECURITY_DATA_ARCHIVAL_REQUEST,SECURITY_DATA_ARCHIVAL_REQUEST_PROCESSED,SECURITY_DATA_RECOVERY_REQUEST,SECURITY_DATA_RECOVERY_REQUEST_PROCESSED,SECURITY_DATA_RECOVERY_REQUEST_STATE_CHANGE,SECURITY_DATA_RETRIEVE_KEY,SYMKEY_GENERATION_REQUEST,SYMKEY_GENERATION_REQUEST_PROCESSED,ASYMKEY_GENERATION_REQUEST
+log.instance.SignedAudit.events=AUDIT_LOG_STARTUP,AUDIT_LOG_SHUTDOWN,ROLE_ASSUME,CONFIG_CERT_POLICY,CONFIG_CERT_PROFILE,CONFIG_CRL_PROFILE,CONFIG_OCSP_PROFILE,CONFIG_AUTH,CONFIG_ROLE,CONFIG_ACL,CONFIG_SIGNED_AUDIT,CONFIG_ENCRYPTION,CONFIG_TRUSTED_PUBLIC_KEY,CONFIG_DRM,SELFTESTS_EXECUTION,AUDIT_LOG_DELETE,LOG_PATH_CHANGE,PRIVATE_KEY_ARCHIVE_REQUEST,PRIVATE_KEY_ARCHIVE_REQUEST_PROCESSED,PRIVATE_KEY_EXPORT_REQUEST_PROCESSED_SUCCESS,PRIVATE_KEY_EXPORT_REQUEST_PROCESSED_FAILURE,KEY_RECOVERY_REQUEST,KEY_RECOVERY_REQUEST_ASYNC,KEY_RECOVERY_AGENT_LOGIN,KEY_RECOVERY_REQUEST_PROCESSED,KEY_RECOVERY_REQUEST_PROCESSED_ASYNC,KEY_GEN_ASYMMETRIC,NON_PROFILE_CERT_REQUEST,PROFILE_CERT_REQUEST,CERT_REQUEST_PROCESSED,CERT_STATUS_CHANGE_REQUEST,CERT_STATUS_CHANGE_REQUEST_PROCESSED,AUTHZ_SUCCESS,AUTHZ_FAIL,INTER_BOUNDARY,AUTH_FAIL,AUTH_SUCCESS,CERT_PROFILE_APPROVAL,PROOF_OF_POSSESSION,CRL_RETRIEVAL,CRL_VALIDATION,CMC_SIGNED_REQUEST_SIG_VERIFY,SERVER_SIDE_KEYGEN_REQUEST_PROCESSED_FAILURE,SERVER_SIDE_KEYGEN_REQUEST_PROCESSED_SUCCESS,SERVER_SIDE_KEYGEN_REQUEST,COMPUTE_SESSION_KEY_REQUEST,COMPUTE_SESSION_KEY_REQUEST_PROCESSED_SUCCESS, COMPUTE_SESSION_KEY_REQUEST_PROCESSED_FAILURE,DIVERSIFY_KEY_REQUEST,DIVERSIFY_KEY_REQUEST_PROCESSED_SUCCESS, DIVERSIFY_KEY_REQUEST_PROCESSED_FAILURE,ENCRYPT_DATA_REQUEST,ENCRYPT_DATA_REQUEST_PROCESSED_SUCCESS,ENCRYPT_DATA_REQUEST_PROCESSED_FAILURE,OCSP_ADD_CA_REQUEST,OCSP_ADD_CA_REQUEST_PROCESSED,OCSP_REMOVE_CA_REQUEST,OCSP_REMOVE_CA_REQUEST_PROCESSED_SUCCESS,OCSP_REMOVE_CA_REQUEST_PROCESSED_FAILURE,COMPUTE_RANDOM_DATA_REQUEST,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_SUCCESS,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_FAILURE,CIMC_CERT_VERIFICATION,CONFIG_SERIAL_NUMBER,SECURITY_DATA_ARCHIVAL_REQUEST,SECURITY_DATA_ARCHIVAL_REQUEST_PROCESSED,SECURITY_DATA_RECOVERY_REQUEST,SECURITY_DATA_RECOVERY_REQUEST_PROCESSED,SECURITY_DATA_RECOVERY_REQUEST_STATE_CHANGE,SECURITY_DATA_RETRIEVE_KEY,SYMKEY_GENERATION_REQUEST,SYMKEY_GENERATION_REQUEST_PROCESSED,ASYMKEY_GENERATION_REQUEST,SECURITY_DATA_RETRIEVE_KEY
 log.instance.SignedAudit.expirationTime=0
 log.instance.SignedAudit.fileName=[PKI_INSTANCE_PATH]/logs/[PKI_SUBSYSTEM_TYPE]/signedAudit/kra_cert-kra_audit
 log.instance.SignedAudit.flushInterval=5
diff --git a/base/kra/src/org/dogtagpki/server/kra/rest/KeyService.java b/base/kra/src/org/dogtagpki/server/kra/rest/KeyService.java
index 56c6f4c6e459c3680403b6962b8047bef83aeccf..bf75ac77906d2477bf9f4c7b95f6e221b07bfa1d 100644
--- a/base/kra/src/org/dogtagpki/server/kra/rest/KeyService.java
+++ b/base/kra/src/org/dogtagpki/server/kra/rest/KeyService.java
@@ -115,22 +115,34 @@ public class KeyService extends PKIService implements KeyResource {
      */
     @Override
     public Response retrieveKey(KeyRecoveryRequest data) {
+        String method = "KeyService.retrieveKey: ";
+        String auditInfo = "Info:KeyService.retrieveKey";
+        CMS.debug(method + "begins.");
         if (data == null) {
-            CMS.debug("retrieveKey: data is null");
-            throw new BadRequestException("Cannot retrieve key. Invalid request");
+            String msg = "Invalid request: data is null";
+            CMS.debug(msg);
+            audit(ILogger.FAILURE, "None", "None", auditInfo + ";" + msg);
+            throw new BadRequestException(method + msg);
         }
         // auth and authz
         RequestId requestID = data.getRequestId();
         IRequest request;
+        KeyId keyId = data.getKeyId();
+
+        if (requestID != null)
+            auditInfo = auditInfo + ": requestID=" + requestID.toString();
+
+        if (keyId != null)
+            auditInfo = auditInfo + "; keyID=" + keyId.toString();
+
         try {
             request = queue.findRequest(requestID);
         } catch (EBaseException e) {
             e.printStackTrace();
-            auditRetrieveKey(ILogger.FAILURE, requestID, null, e.getMessage());
+            audit(ILogger.FAILURE, requestID, null, auditInfo + ";" + e.getMessage());
             throw new PKIException(e.getMessage());
         }
         String type = request.getRequestType();
-        KeyId keyId = null;
         KeyData keyData;
         try {
             if (IRequest.KEYRECOVERY_REQUEST.equals(type)) {
@@ -139,17 +151,17 @@ public class KeyService extends PKIService implements KeyResource {
                 keyId = validateRequest(data);
                 keyData = getKey(keyId, data);
             }
-        } catch (EBaseException e) {
+        } catch (Exception e) {
             e.printStackTrace();
-            auditRetrieveKey(ILogger.FAILURE, requestID, keyId, e.getMessage());
+            audit(ILogger.FAILURE, requestID, keyId, auditInfo + ";" + e.getMessage());
             throw new PKIException(e.getMessage());
         }
         if (keyData == null) {
             // no key record
-            auditRetrieveKey(ILogger.FAILURE, requestID, keyId, "No key record");
+            audit(ILogger.FAILURE, requestID, keyId, auditInfo + "; No key record");
             throw new HTTPGoneException("No key record.");
         }
-        auditRetrieveKey(ILogger.SUCCESS, requestID, keyId, "None");
+        audit(ILogger.SUCCESS, requestID, keyId, auditInfo);
 
         return createOKResponse(keyData);
     }
@@ -157,13 +169,17 @@ public class KeyService extends PKIService implements KeyResource {
     // retrieval - used to test integration with a browser
     @Override
     public Response retrieveKey(MultivaluedMap<String, String> form) {
+        String method = "KeyService.retrieveKey with form: ";
+        CMS.debug(method + "begins.");
         KeyRecoveryRequest data = new KeyRecoveryRequest(form);
         return retrieveKey(data);
     }
 
     public KeyData getKey(KeyId keyId, KeyRecoveryRequest data) throws EBaseException {
+        String method = "KeyService.getKey: ";
+        String auditInfo = null;
         KeyData keyData;
-
+        CMS.debug(method + "begins.");
         RequestId rId = data.getRequestId();
 
         String transWrappedSessionKey;
@@ -172,12 +188,15 @@ public class KeyService extends PKIService implements KeyResource {
         IRequest request = queue.findRequest(rId);
 
         if (request == null) {
+            CMS.debug(method + "request null");
             return null;
         }
 
      // get wrapped key
         IKeyRecord rec = repo.readKeyRecord(keyId.toBigInteger());
         if (rec == null) {
+            CMS.debug(method + "key record null");
+
             return null;
         }
 
@@ -185,8 +204,9 @@ public class KeyService extends PKIService implements KeyResource {
                 request.getRequestId());
 
         if(requestParams == null) {
-            auditRetrieveKey(ILogger.FAILURE, rId, keyId, "cannot obtain volatile requestParams");
-            throw new EBaseException("Can't obtain Volatile requestParams in getKey!");
+            auditInfo = method + "Can't obtain Volatile requestParams in getKey!";
+            CMS.debug(auditInfo);
+            throw new EBaseException(auditInfo);
         }
 
         String sessWrappedKeyData = (String) requestParams.get(IRequest.SECURITY_DATA_SESS_WRAPPED_DATA);
@@ -210,8 +230,9 @@ public class KeyService extends PKIService implements KeyResource {
             if (transWrappedSessionKey == null) {
                 //There must be at least a transWrappedSessionKey input provided.
                 //The command AND the request have provided insufficient data, end of the line.
-                auditRetrieveKey(ILogger.FAILURE, rId, keyId, "insufficient input data");
-                throw new EBaseException("Can't retrieve key, insufficient input data!");
+                auditInfo = method + "Can't retrieve key, insufficient input data!";
+                CMS.debug(auditInfo);
+                throw new EBaseException(auditInfo);
             }
 
             if (sessionWrappedPassphrase != null) {
@@ -231,8 +252,9 @@ public class KeyService extends PKIService implements KeyResource {
                 request.setRequestStatus(RequestStatus.BEGIN);
                 queue.processRequest(request);
             } catch (EBaseException e) {
+                auditInfo = method + e.getMessage();
                 kra.destroyVolatileRequest(request.getRequestId());
-                throw new EBaseException(e.toString());
+                throw new EBaseException(auditInfo);
             }
 
             nonceData = null;
@@ -273,21 +295,27 @@ public class KeyService extends PKIService implements KeyResource {
     }
 
     private KeyId validateRequest(KeyRecoveryRequest data) {
+        String method = "KeyService.validateRequest: ";
+        CMS.debug(method + "begins.");
+        String logMessage = null;
 
         // confirm request exists
         RequestId reqId = data.getRequestId();
         if (reqId == null) {
-            auditRetrieveKey(ILogger.FAILURE, null, null, "Request id not found");
             // log error
-            throw new BadRequestException("Request id not found.");
+            logMessage = "Request id not found.";
+            CMS.debug(logMessage);
+            throw new BadRequestException(logMessage);
         }
 
         // confirm that at least one wrapping method exists
         // There must be at least the wrapped session key method.
         if ((data.getTransWrappedSessionKey() == null)) {
-            auditRetrieveKey(ILogger.FAILURE, reqId, null, "No wrapping method found");
             // log error
-            throw new BadRequestException("No wrapping method found.");
+            logMessage = "No wrapping method found.";
+            CMS.debug(logMessage);
+
+            throw new BadRequestException(logMessage);
         }
 
         KeyRequestDAO reqDAO = new KeyRequestDAO();
@@ -295,23 +323,28 @@ public class KeyService extends PKIService implements KeyResource {
         try {
             reqInfo = reqDAO.getRequest(reqId, uriInfo);
         } catch (EBaseException e1) {
-            auditRetrieveKey(ILogger.FAILURE, reqId, null, "failed to get request");
             // failed to get request
+            logMessage = "failed to get request";
+            CMS.debug(logMessage);
+
             e1.printStackTrace();
-            throw new PKIException(e1.getMessage());
+            throw new PKIException(logMessage + e1.getMessage());
         }
         if (reqInfo == null) {
-            auditRetrieveKey(ILogger.FAILURE, reqId, null, "no request info available");
             // request not found
-            throw new HTTPGoneException("No request information available.");
+            logMessage = "No request information available.";
+            CMS.debug(logMessage);
+
+            throw new HTTPGoneException(logMessage);
         }
 
         //confirm request is of the right type
         String type = reqInfo.getRequestType();
         if (!type.equals(IRequest.SECURITY_DATA_RECOVERY_REQUEST)) {
-            auditRetrieveKey(ILogger.FAILURE, reqId, null, "invalid request type");
             // log error
-            throw new BadRequestException("Invalid request type");
+            logMessage = "Invalid request type";
+            CMS.debug(logMessage);
+            throw new BadRequestException(logMessage);
         }
 
         //confirm that retriever is originator of request, else throw 401
@@ -321,22 +354,25 @@ public class KeyService extends PKIService implements KeyResource {
             request = queue.findRequest(reqId);
         } catch (EBaseException e) {
             e.printStackTrace();
-            auditRetrieveKey(ILogger.FAILURE, reqId, null, "unable to retrieve recovery request");
-            throw new PKIException(e.getMessage());
+            logMessage = e.getMessage();
+            CMS.debug(logMessage);
+
+            throw new PKIException(logMessage);
         }
         String originator = request.getExtDataInString(IRequest.ATTR_REQUEST_OWNER);
         if (! originator.equals(retriever)) {
-            auditRetrieveKey(ILogger.FAILURE, reqId, null, "recovery request not approved.  originator does not match retriever");
-            throw new UnauthorizedException(
-                    "Data for recovery requests can only be retrieved by the originators of the request");
+            logMessage = "Data for recovery requests can only be retrieved by the originators of the request";
+            CMS.debug(logMessage);
+            throw new UnauthorizedException(logMessage);
         }
 
         // confirm request is in approved state
         RequestStatus status = reqInfo.getRequestStatus();
         if (!status.equals(RequestStatus.APPROVED)) {
-            auditRetrieveKey(ILogger.FAILURE, reqId, null, "recovery request not approved");
             // log error
-            throw new UnauthorizedException("Unauthorized request.  Recovery request not approved.");
+            logMessage = "Unauthorized request.  Recovery request not approved.";
+            CMS.debug(logMessage);
+            throw new UnauthorizedException(logMessage);
         }
 
         return reqInfo.getKeyId();
@@ -348,11 +384,17 @@ public class KeyService extends PKIService implements KeyResource {
     @Override
     public Response listKeys(String clientKeyID, String status, Integer maxResults, Integer maxTime,
             Integer start, Integer size) {
+        String method = "KeyService.listKeys: ";
+        CMS.debug(method + "begins.");
+
         return createOKResponse(listKeyInfos(clientKeyID, status, maxResults, maxTime, start, size));
     }
 
     public KeyInfoCollection listKeyInfos(String clientKeyID, String status, Integer maxResults, Integer maxTime,
             Integer start, Integer size) {
+        String method = "KeyService.listKeyInfos: ";
+        String auditInfo = "Info: KeyService.listKeyInfos; status =" + status;
+        CMS.debug(method + "begins.");
 
         start = start == null ? 0 : start;
         size = size == null ? DEFAULT_SIZE : size;
@@ -398,15 +440,21 @@ public class KeyService extends PKIService implements KeyResource {
             }
 
         } catch (EBaseException e) {
+            audit(ILogger.FAILURE, null, clientKeyID, e.getMessage() + auditInfo);
+
             e.printStackTrace();
             throw new PKIException(e.getMessage());
         }
+        audit(ILogger.SUCCESS, null, clientKeyID, auditInfo);
 
         return infos;
     }
 
     @Override
     public Response getActiveKeyInfo(String clientKeyID) {
+        String method = "KeyService.getActiveKeyInfo: ";
+        String auditInfo = "Info: KeyService.getActiveKeyInfo";
+        CMS.debug(method + "begins.");
 
         KeyInfoCollection infos = listKeyInfos(
                 clientKeyID,
@@ -424,14 +472,21 @@ public class KeyService extends PKIService implements KeyResource {
             KeyInfo info = iter.next();
             if (info != null) {
                 // return the first one
+                audit(ILogger.SUCCESS, null, clientKeyID, auditInfo);
+
                 return createOKResponse(info);
             }
         }
+        String message = "Key not found.";
+        audit(ILogger.FAILURE, null, clientKeyID, message + auditInfo);
 
-        throw new ResourceNotFoundException("Key not found.");
+        throw new ResourceNotFoundException(auditInfo + ":" + message);
     }
 
     public KeyInfo createKeyDataInfo(IKeyRecord rec, boolean getPublicKey) throws EBaseException {
+        String method = "KeyService.createKeyDataInfo: ";
+        CMS.debug(method + "begins.");
+
         KeyInfo ret = new KeyInfo();
         ret.setClientKeyID(rec.getClientId());
         ret.setStatus(rec.getKeyStatus());
@@ -478,13 +533,18 @@ public class KeyService extends PKIService implements KeyResource {
         return filter;
     }
 
-    public void auditRetrieveKey(String status, RequestId requestID, KeyId keyID, String reason) {
+    public void audit(String status, RequestId requestID, KeyId keyID, String reason) {
+        audit(status, requestID != null ? requestID.toString(): "null",
+                keyID != null ? keyID.toString(): "null", reason);
+    }
+
+    public void audit(String status, String requestID, String keyID, String reason) {
         String msg = CMS.getLogMessage(
                 LOGGING_SIGNED_AUDIT_SECURITY_DATA_RETRIEVE_KEY,
                 servletRequest.getUserPrincipal().getName(),
                 status,
-                requestID != null ? requestID.toString(): "null",
-                keyID != null ? keyID.toString(): "null",
+                requestID,
+                keyID,
                 reason);
         auditor.log(msg);
     }
@@ -494,7 +554,11 @@ public class KeyService extends PKIService implements KeyResource {
      * @param data
      * @return
      */
-    private KeyData recoverKey(KeyRecoveryRequest data) {
+    private KeyData recoverKey(KeyRecoveryRequest data) throws UnauthorizedException, HTTPGoneException {
+        String method = "KeyService.recoverKey: ";
+        String auditInfo = "KeyService.recoverKey";
+        CMS.debug(method + "begins.");
+
         // confirm request exists
         RequestId reqId = data.getRequestId();
 
@@ -504,14 +568,15 @@ public class KeyService extends PKIService implements KeyResource {
         } catch (EBaseException e) {
         }
         if (request == null) {
-            throw new HTTPGoneException("No request record.");
+            auditInfo = method + "No request record.";
+            throw new HTTPGoneException(auditInfo);
         }
         String type = request.getRequestType();
         RequestStatus status = request.getRequestStatus();
         if (!IRequest.KEYRECOVERY_REQUEST.equals(type) ||
             !status.equals(RequestStatus.APPROVED)) {
-            auditRetrieveKey(ILogger.FAILURE, reqId, null, "Unauthorized request.");
-            throw new UnauthorizedException("Unauthorized request.");
+            auditInfo = method + "Unauthorized request.";
+            throw new UnauthorizedException(auditInfo);
         }
 
         String passphrase = data.getPassphrase();
@@ -521,7 +586,8 @@ public class KeyService extends PKIService implements KeyResource {
         } catch (EBaseException e) {
         }
         if (pkcs12 == null) {
-            throw new HTTPGoneException("Key not recovered.");
+            auditInfo = method + "pkcs12 null; Key not recovered.";
+            throw new HTTPGoneException(auditInfo);
         }
         String pkcs12base64encoded = Utils.base64encode(pkcs12);
 
@@ -539,16 +605,26 @@ public class KeyService extends PKIService implements KeyResource {
 
     @Override
     public Response getKeyInfo(KeyId keyId) {
+        String method = "KeyService.getKeyInfo: ";
+        String auditInfo = "Info: KeyService.getKeyInfo";
+        CMS.debug(method + "begins.");
+
         IKeyRecord rec = null;
         try {
             rec = repo.readKeyRecord(keyId.toBigInteger());
             KeyInfo info = createKeyDataInfo(rec, true);
+            audit(ILogger.SUCCESS, null, keyId, auditInfo);
 
             return createOKResponse(info);
         } catch (EDBRecordNotFoundException e) {
+            auditInfo = method + e.getMessage();
+            audit(ILogger.FAILURE, null, keyId, auditInfo);
+
             throw new KeyNotFoundException(keyId);
         } catch (Exception e) {
-            CMS.debug("Unable to retrieve key record: " + e);
+            auditInfo = method + "Unable to retrieve key record: " + e.getMessage();
+            audit(ILogger.FAILURE, null, keyId, auditInfo);
+            CMS.debug(auditInfo);
             e.printStackTrace();
             throw new PKIException(e.getMessage());
         }
@@ -556,16 +632,28 @@ public class KeyService extends PKIService implements KeyResource {
 
     @Override
     public Response modifyKeyStatus(KeyId keyId, String status) {
+        String method = "KeyService.modifyKeyStatus: ";
+        //TODO: what was the original status?  find it and record that in Info as well
+        String auditInfo = "Info: KeyService.modifyKeyStatus; status=" + status;
+
+        CMS.debug(method + "begins.");
+
         try {
 
             ModificationSet mods = new ModificationSet();
             mods.add(IKeyRecord.ATTR_STATUS, Modification.MOD_REPLACE,
                     status);
             repo.modifyKeyRecord(keyId.toBigInteger(), mods);
+            audit(ILogger.SUCCESS, null, keyId, auditInfo);
+
             return createNoContentResponse();
         } catch (EDBRecordNotFoundException e) {
+            auditInfo = method + e.getMessage();
+            audit(ILogger.FAILURE, null, keyId, auditInfo);
             throw new KeyNotFoundException(keyId);
         } catch (Exception e) {
+            auditInfo = method + e.getMessage();
+            audit(ILogger.FAILURE, null, keyId, auditInfo);
             CMS.debug("Unable to retrieve key record: " + e);
             e.printStackTrace();
             throw new PKIException(e.getMessage());
-- 
1.8.4.2

