Bug 1550581

Summary: CMCAuth throws org.mozilla.jss.crypto.TokenException: Unable to insert certificate into temporary database [rhel-7.5.z]
Product: Red Hat Enterprise Linux 7 Reporter: Oneata Mircea Teodor <toneata>
Component: pki-coreAssignee: Christina Fu <cfu>
Status: CLOSED ERRATA QA Contact: Asha Akkiangady <aakkiang>
Severity: urgent Docs Contact: Marc Muehlfeld <mmuehlfe>
Priority: urgent    
Version: 7.5CC: cfu, gkapoor, mharmsen, msauton
Target Milestone: rcKeywords: TestCaseProvided, ZStream
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: pki-core-10.5.1-10.el7 Doc Type: Bug Fix
Doc Text:
Previously, when ECC keys were enrolled, Certificate Management over CMS (CMC) authentication failed with a "TokenException: Unable to insert certificate into temporary database" error. As a consequence, the enrollment failed. This update fixes the problem. As a result, the mentioned bug no longer occurs.
 Story Points: ---
Clone Of: 1548124 Environment:
Last Closed: 2018-06-26 16:47:58 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1548124    
Bug Blocks:    

Description Oneata Mircea Teodor 2018-03-01 14:16:30 UTC 
This bug has been copied from bug #1548124 and has been proposed to be backported to 7.5 z-stream (EUS).
Comment 2 Matthew Harmsen 2018-03-06 17:35:29 UTC 
commit 7f4eae3c78daf8d56b76153e3f48086a804c3d3d
Author: Christina Fu <cfu>
Date:   Mon Feb 26 14:01:18 2018 -0800

    Ticket #2949 CMCAuth throws org.mozilla.jss.crypto.TokenException: Unable to insert certificate into temporary database
    
    This patch addresses the "TokenException: Unable to insert certificate into temporary database" issue caused by CMC authentication.  During the CMC authentication, looks like the following JSS CryptoManager call actually tries to import the certificate temporarily into the token and causes conflicts:
    public boolean isCertValid(byte[] certPackage, boolean checkSig,
                CertUsage certUsage)
    That call is not appropriate for the purpose.
    
    Looking closely,  certificate validation has been done in various places:
    * SSL client authentication (if used)
    * the isRevoked() call either in agent authentication or in CMCUserSignedAuth
    * the cert.checkValidity() call in CMCUserSignedAuth
    
    The extra isCertValid call is not only redundant but also problematic.
    
    This patch fixes https://pagure.io/dogtagpki/issue/2949
    (cherry picked from commit c6630a429f6f4a9b2c2090001f0a2c50e10ba5c4)
    
    Change-Id: I47367b02c8a53a9cfa99b5da370a3a6af1cb9676
Comment 5 Christina Fu 2018-04-11 16:15:07 UTC 
Please note that I made the adjustment from
"As a consequence, the import of the certificate into the database failed."
to
"As a consequence, the enrollment failed."
because the certificate should NOT be imported in the first place. The fix took care of that.  There is no need to explain in such detail as that'd really confuse people.
Comment 6 Geetika Kapoor 2018-04-18 11:15:02 UTC 
Testing is blocked because KRA installation is having issues with key archival.
I have a BZ for it.
https://bugzilla.redhat.com/show_bug.cgi?id=1568615
I can't test CMC archival due to this issue.
Comment 7 Geetika Kapoor 2018-05-09 12:47:27 UTC 
I tried the hacky workaround and KRA installation works.Archival too works.

Now I am seeing issues with test case when we set "-a ec" in CRMFPopClient and request.selfSign=true in case of self signed user case.
It fails with [04/May/2018:07:25:41][http-bio-20443-exec-16]: CMCUserSignedAuth: authenticate: org.mozilla.jss.crypto.InvalidKeyFormatException: Unable to decode DER-encoded SubjectPublicKeyInfo: invalid DER encoding



basically for self-signed cases whenever cmc.cfg file has request.selfSign=true , and signing algorithm is EC( as in crmfpopclient cli we use -a ec)

CRMFPopClient -d /root/help -p SECret.123 -n UID=testuser1self-Test1 -q POP_SUCCESS -b /root/transport.pem -a ec -t false -y -w "AES/CBC/PKCS5Padding" -o crmf2.req
[04/May/2018:07:25:41][http-bio-20443-exec-16]: CMCUserSignedAuth: authenticate: signing key alg=EC
[04/May/2018:07:25:41][http-bio-20443-exec-16]: CMCUserSignedAuth: authenticate: org.mozilla.jss.crypto.InvalidKeyFormatException: Unable to decode DER-encoded SubjectPublicKeyInfo: invalid DER encoding

In Case we have signing algorithm as RSA in crmfpopclient,it works.
=====================================================

CRMFPopClient -d /root/help -p SECret.123 -n UID=testuser1self-Test1 -q POP_SUCCESS -b /root/transport.pem -y -w "AES/CBC/PKCS5Padding" -o crmf2.req

[04/May/2018:07:40:57][http-bio-20443-exec-17]: CMCUserSignedAuth: authenticate: signing key alg=RSA
[04/May/2018:07:40:57][http-bio-20443-exec-17]: CMCUserSignedAuth: authenticate: public key retrieved
[04/May/2018:07:40:57][http-bio-20443-exec-17]: CMCUserSignedAuth: verifySelfSignedCMC: begins
Comment 8 Geetika Kapoor 2018-05-16 12:10:15 UTC 
I think once we have a fix for this or maybe complete steps about ECC procedure we need to document it somewhere for users.Maybe in man page or maybe in installation guide.I am just waiting for above comment to get addressed and re-test it again with a complete fix of https://bugzilla.redhat.com/show_bug.cgi?id=1568615
Comment 9 Geetika Kapoor 2018-06-15 17:13:22 UTC 
Due to shortage of time, I am able to perform 1 quick test for this bug.
I will cover rest of the testing later.
I will add more test cases later.

Test Case 1: Run CMC/Http with CRMFPopClient with -a and request.selfSign=true
===============================================================================

1.Run crmfpopclient.

# CRMFPopClient -d subca-db/ -p SECret.123 -n UID=testuser100 -b transport.pem  -a ec -t false -y  -w "AES/CBC/PKCS5Padding" -o crmf2.req
Keypair private key id: 5150274d0e01d4f42bdd8f8865edb4046148967a
CRMFPopClient: self_sign true. Generating SubjectKeyIdentifier extension.
CryptoUtil: createKeyIdentifier: begins
Storing CRMF requrest into crmf2.req


2. Now run cmc request file after setting correct private id in 

3. Now run HttpClient with profile == caECFullCMCSelfSignedCert

4. Now send Http Request.

11. Make sure cert is generated and is archived.

verification 1: Check logs for both KRA and CA
-------------

debug logs CA:


[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SignedAuditLogger: event ACCESS_SESSION_ESTABLISH
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet:service() uri = /ca/ee/ca/profileSubmitCMCFull
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet::service() param name='profileId' value='caECFullCMCSelfSignedCert'
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet: caProfileSubmitCMCFull start to service.
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: Start of ProfileSubmitCMCServlet Input Parameters
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet Input Parameter profileId='caECFullCMCSelfSignedCert'
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: End of ProfileSubmitCMCServlet Input Parameters
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: start serving
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: SubId=profile
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: profileId caECFullCMCSelfSignedCert
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: authenticator CMCUserSignedAuth found
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: set Inputs into Context
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: set sslClientCertProvider
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet: in auditSubjectID
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet: auditSubjectID auditContext {sslClientCertProvider=com.netscape.cms.servlet.profile.SSLClientCertProvider@73fbf03e, profileContext=com.netscape.cms.profile.common.ProfileContext@36f96025}
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet auditSubjectID: subjectID: null
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate: begins
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth:createAuditSubjectFromCert:  Principal name = UID=test10,CN=test10,O=example.org
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate: cmc request content is signed data
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: verifySignerInfo: begins
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: verifySignerInfo: SignerIdentifier type: SUBJECT_KEY_IDENTIFIER
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: verifySignerInfo: selfSigned is true
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate:  self-signed cmc request will not have user identification info at this point.
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate: numReqs not 0, assume enrollment request
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate:  type is CRMF
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate: setting requestCertSubject to: 
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate: SubjectKeyIdentifierExtension found
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate: signing key alg=EC
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate: got X509Key 
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate: public key retrieved
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: verifySelfSignedCMC: begins
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: verifySelfSignedCMC:  SignerIdentifier SUBJECT_KEY_IDENTIFIER matches SKI of request
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: verifySelfSignedCMC: verifying request signature with public key
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: verifySelfSignedCMC:  signature verified
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SignedAuditLogger: event CMC_USER_SIGNED_REQUEST_SIG_VERIFY
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCUserSignedAuth: authenticate: ends successfully; returning authToken
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: authenticate: setting auditSubjectID in SessionContext:$Unidentified$
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet authToken not null
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet.authorize(DirAclAuthz)
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet: in auditSubjectID
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet: auditSubjectID auditContext {sslClientCertProvider=com.netscape.cms.servlet.profile.SSLClientCertProvider@73fbf03e, cmcRequestCertSubject=<null>, userid=$Unidentified$, profileContext=com.netscape.cms.profile.common.ProfileContext@36f96025, sslClientCert=[
[
  Version: V3
  Subject: UID=test10,CN=test10,O=example.org
  Signature Algorithm: SHA384withEC, OID = 1.2.840.10045.4.3.3

  Key:  algorithm = RSA, unparsed keybits = 
30 81 89 02 81 81 00 C0 97 5B 81 DD 9C D9 5C A0 D1 F4 F0 9A 
CF 7D C7 E1 C5 A4 3F A6 2E 0B 77 27 54 71 0D 2A AC 62 9B 46 
E6 89 24 09 63 34 DE 5A 86 00 C2 DD 64 06 66 63 17 04 2A EC 
A8 19 46 1E 1A 5D B5 15 26 4C 3A 6A 00 64 85 62 EA A2 38 3F 
2D C0 CF 87 44 4B 01 22 6B 42 9A 02 7F AA 70 5F 94 36 CE 04 
5C AB D6 A8 32 22 7D 4A AC 22 D3 9C CF CB 61 18 08 C3 73 14 
B9 37 21 07 63 B0 54 CA 98 F2 FA BA 35 67 65 02 03 01 00 01

  Validity: [From: Fri Jun 15 10:48:45 EDT 2018,
               To: Wed Dec 12 10:48:45 EST 2018]
  Issuer: CN=Company Root CA2,O=Company,C=US
  SerialNumber: [    0f]
  Extension[0] = ObjectId: 2.5.29.35 Criticality=false
AuthorityKeyIdentifier [
KeyIdentifier [
74 10 CB CF 97 7A 7C 66 95 E4 AF 92 10 34 F0 25 07 56 B2 16
]
]
  Extension[1] = ObjectId: 1.3.6.1.5.5.7.1.1 Criticality=false
AuthInfoAccess [
(0) 1.3.6.1.5.5.7.48.1 URIName: http://nocp4.idm.lab.eng.rdu2.redhat.com:28080/ca/ocsp]
  Extension[2] = ObjectId: 2.5.29.15 Criticality=true
KeyUsage [
  DigitalSignature
  Non_repudiation
  Key_Encipherment
]
  Extension[3] = oid=2.5.29.37  val=48 20 6 8 43 6 1 5 5 7 3 2 6 8 43 6 1 5 5 7 3 4 
]
  Algorithm: [SHA384withEC]
  Signature:
30 64 02 30 04 DD BF 58 36 12 61 AD 26 C2 03 0B AB BF 67 33 
ED 22 E7 8A 0F 3D 1D F6 03 89 D7 83 22 83 F1 95 C9 12 D5 8A 
4B ED 08 45 7C 05 AE DF 6B 46 EC 4E 02 30 12 F9 2B 61 CD 7A 
8B 0B D1 CC 6A C1 87 19 0E 85 E6 64 BE 86 41 CF 4A D5 61 02 
0C B4 FA DE 0E 4E 3B 1D FA 38 D8 55 EF 3A C1 A0 E8 9C 64 90 
B8 C4
], authManagerId=CMCUserSignedAuth}
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet auditSubjectID: subjectID: $Unidentified$
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet: in auditGroupID
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet: auditGroupID auditContext {sslClientCertProvider=com.netscape.cms.servlet.profile.SSLClientCertProvider@73fbf03e, cmcRequestCertSubject=<null>, userid=$Unidentified$, profileContext=com.netscape.cms.profile.common.ProfileContext@36f96025, sslClientCert=[
[
  Version: V3
  Subject: UID=test10,CN=test10,O=example.org
  Signature Algorithm: SHA384withEC, OID = 1.2.840.10045.4.3.3

  Key:  algorithm = RSA, unparsed keybits = 
30 81 89 02 81 81 00 C0 97 5B 81 DD 9C D9 5C A0 D1 F4 F0 9A 
CF 7D C7 E1 C5 A4 3F A6 2E 0B 77 27 54 71 0D 2A AC 62 9B 46 
E6 89 24 09 63 34 DE 5A 86 00 C2 DD 64 06 66 63 17 04 2A EC 
A8 19 46 1E 1A 5D B5 15 26 4C 3A 6A 00 64 85 62 EA A2 38 3F 
2D C0 CF 87 44 4B 01 22 6B 42 9A 02 7F AA 70 5F 94 36 CE 04 
5C AB D6 A8 32 22 7D 4A AC 22 D3 9C CF CB 61 18 08 C3 73 14 
B9 37 21 07 63 B0 54 CA 98 F2 FA BA 35 67 65 02 03 01 00 01

  Validity: [From: Fri Jun 15 10:48:45 EDT 2018,
               To: Wed Dec 12 10:48:45 EST 2018]
  Issuer: CN=Company Root CA2,O=Company,C=US
  SerialNumber: [    0f]
  Extension[0] = ObjectId: 2.5.29.35 Criticality=false
AuthorityKeyIdentifier [
KeyIdentifier [
74 10 CB CF 97 7A 7C 66 95 E4 AF 92 10 34 F0 25 07 56 B2 16
]
]
  Extension[1] = ObjectId: 1.3.6.1.5.5.7.1.1 Criticality=false
AuthInfoAccess [
(0) 1.3.6.1.5.5.7.48.1 URIName: http://nocp4.idm.lab.eng.rdu2.redhat.com:28080/ca/ocsp]
  Extension[2] = ObjectId: 2.5.29.15 Criticality=true
KeyUsage [
  DigitalSignature
  Non_repudiation
  Key_Encipherment
]
  Extension[3] = oid=2.5.29.37  val=48 20 6 8 43 6 1 5 5 7 3 2 6 8 43 6 1 5 5 7 3 4 
]
  Algorithm: [SHA384withEC]
  Signature:
30 64 02 30 04 DD BF 58 36 12 61 AD 26 C2 03 0B AB BF 67 33 
ED 22 E7 8A 0F 3D 1D F6 03 89 D7 83 22 83 F1 95 C9 12 D5 8A 
4B ED 08 45 7C 05 AE DF 6B 46 EC 4E 02 30 12 F9 2B 61 CD 7A 
8B 0B D1 CC 6A C1 87 19 0E 85 E6 64 BE 86 41 CF 4A D5 61 02 
0C B4 FA DE 0E 4E 3B 1D FA 38 D8 55 EF 3A C1 A0 E8 9C 64 90 
B8 C4
], authManagerId=CMCUserSignedAuth}
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMSServlet auditGroupID: groupID: null
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: AAclAuthz.checkPermission(certServer.ee.profile, submit)
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: checkAllowEntries(): expressions: user="anybody"
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: evaluating expressions: user="anybody"
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: evaluated expression: user="anybody" to be true
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: DirAclAuthz: authorization passed
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SignedAuditLogger: event AUTHZ
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SignedAuditLogger: event CMC_REQUEST_RECEIVED
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: createRequests: begins
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: starts
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: getPKIDataFromCMCblob: starts
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: getPKIDataFromCMCblob: cmc request content is signed data
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: authManagerId =CMCUserSignedAuth
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: numcontrols=3
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: about to pre-process controls
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: id_cmc_idPOPLinkRandom found
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC:  id_cmc_identification found
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC:  id_cmc_identityProofV2 found
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: processing controls...
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: not pre-signed CMC request; calling verifyIdentityProofV2;
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile:verifyIdentityProofV2:  begins
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SharedSecret.getSharedToken(String identification): begins.
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SharedSecret.getSharedToken(String identification): searching for identification =user3a; mShrTokAttr =shrTokTesting
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: In LdapBoundConnFactory::getConn()
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: masterConn is connected: true
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: getConn: conn is connected true
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: getConn: mNumConns now 4
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SharedSecret.getSharedToken(String identification):  got entryShrTok
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SharedSecret.decryptShrTokData: wrapped session key retrieved
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SharedSecret.decryptShrTokData: wrapped passphrase retrieved
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SharedSecret.getSharedToken(String identification): returning
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: returnConn: mNumConns now 5
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile:verifyDigest: in verifyDigest: hashAlg=SHA-512 Message Digest from Mozilla-JSS, <initialized>
; macAlg=SHA-256 Message Digest from Mozilla-JSS, <initialized>

[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile:verifyDigest:  The content of two HMAC digest are the same.
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile:verifyIdentityProofV2: current auditSubjectID was:$Unidentified$
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile:verifyIdentityProofV2: identity verified. Updating auditSubjectID
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile:verifyIdentityProofV2: updated auditSubjectID is:user3a
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: passed verifyIdentityProofV2; Proof of Identity successful;
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: got randomSeed
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: found numOfOtherMsgs: 0
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: getting :cmc.popLinkWitnessRequired
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: popLinkWitness(V2) not required
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: nummsgs =1
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: parseCMC: ends
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: createRequests: parseCMC returns cmc_msgs num_requests=1
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: Repository: in getNextSerialNumber. 
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: Repository: checkRange  mLastSerialNo=22
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: Repository: getNextSerialNumber: returning retSerial 22
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: setDefaultCertInfo: setting issuerDN using exact CA signing cert subjectDN encoding
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: createEnrollmentRequest 22
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: createRequests: setting cmc TaggedRequest in request
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet profileSetid=cmcUserCertSet
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: request 22
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: populating request inputs
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCCertReqInput: populate: begins
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: getPKIDataFromCMCblob: starts
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: getPKIDataFromCMCblob: cmc request content is signed data
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CMCCertReqInput: populate: pkiData.getReqSequence() called; nummsgs =1
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: fillTaggedRequest: begins
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: fillTaggedRequest: CRMF:  TaggedRequest type == crmf
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: fillTaggedRequest: CRMF: getting :cmc.lraPopWitness.verify.allow
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: fillTaggedRequest: CRMF: cmc.lraPopWitness.verify.allow is false
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: fillTaggedRequest: CRMF:  hasPop true
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: verifyPOP: for signing keys begins.
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: verifyPOP: POP verification using internal token
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SignedAuditLogger: event PROOF_OF_POSSESSION
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: verifyPOP: done.
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: fillCertReqMsg: Start parseCertReqMsg 
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile:  validity not supplied
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: fillCertReqMsg: found extension:{2 5 29 14}
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: fillCertReqMsg: found SUBJECT_KEY_IDENTIFIER extension
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: populate: begins
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: BasicProfile: populate: policy setid =cmcUserCertSet
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: UserSubjectNameDefault: start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: UserSubjectNameDefault: end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: ValidityDefault: start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityDefault: start time: 0
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityDefault: not before: Fri Jun 15 11:47:12 EDT 2018
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityDefault: range: 180
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityDefault: range unit: day
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityDefault: not after: Wed Dec 12 11:47:12 EST 2018
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: ValidityDefault: end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: UserKeyDefault: start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: UserKeyDefault: end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: AuthorityKeyIdentifierExtDefault: start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: AuthorityKeyIdentifierExtDefault: end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: AuthInfoAccessExtDefault: start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: AuthInfoAccess: createExtension i=0
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: AuthInfoAccessExtDefault: end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: KeyUsageExtDefault: start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: KeyUsageExtDefault: end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: ExtendedKeyUsageExtDefault: start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: ExtendedKeyUsageExtDefault: end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: SigningAlgDefault: start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollDefault: populate: SigningAlgDefault: end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.profileapprovedby$ value=admin
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.auth_token.cmcselfsigned$ value=true
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.authenticatedname$ value=
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.cert_request$ value=oYIDHDCCAsACAQEwgZ6AAQKlHzAdMRswGQYKCZImiZPyLGQBARMLdGVzdHVzZXIx
MDCmWTATBgcqhkjOPQIBBggqhkjOPQMBBwNCAATLmbMbReUO1fOv9kuOjFLMyxDI
2+wBLw7L3dAoWnFgwg4knBDmdUuinaRp12h5w56DD5RzLULsCZKf/AgqPU6dqR0w
GwYDVR0OBBRRUCdNDgHU9Cvdj4hl7bQEYUiWejCCAhgwggHLBgkrBgEFBQcFAQSg
ggG8MIIBuKEdBglghkgBZQMEAQIEEDbl+fBqlyDomYIYVGprU9GCggEBACVIRijZ
9AUviI48G01Y7C/ql1dADzMDqi7dgbNtPxm0dTG7yhPIjsat+HrliC6N7zomfiPC
ngX1fE1aSxZHuYjHeiu04ZJWOsOQ+1/Gm6mE2FagmSQquhwwCh99Wz3vP2zuWf+N
idKmFN9KGTX7fWCUcCtHxT1nOVfVoYkRUYLzHCw/Byn4Q5eX/Cw2dtmSU7rJ4PQD
d3o5fDBIJ1K6o+dpZx7tjU2qUJcLu08WpUQ47wNZUYJtOTfpK6ZQL54RFKQuTVFg
RYqDjCqNhX3Iy3ha0VqE/JO1dQcKqewdefKjdRlRHH3wSq1qojuKHSXoG0MlinBW
rLUkppQXFBi7D9MDgZEAHBQ+hQg/ks4Rg/4TW/kcP0oCQHr5iwVDCAph7ILYSR2j
XTcDkhF4jso9C1Ekjr/QOQ4NNCLmxdpKKTbGkdOT29wPsrKWP59ojkTrYxibkXmi
o3gCilLdA7lsCpACnQBsN80GZTDEIZ/yMEwWRI1seSbLlCBxIIK2NBnA2UVWcQtf
MoG1gjj1oW7NQkLACWwlMEcGCCsGAQUFBwchMDswCwYJYIZIAWUDBAIBMAoGCCqG
SIb3DQIJBCAwftFnhCJ3dlfC1+a9ZNQTOylD0jnlyBht+qf4qGhHqaFWMAoGCCqG
SM49BAMCA0gAMEUCIQCkrT2T/0dUPAVuVfnWTNqZZFDFWho7Yxkv6W1b0aNBiQIg
BBUAP0JPRN14lIjH6agIxFWfmWeeuvDqG0nXM6fq4Iw=

[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.profile$ value=true
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.requestversion$ value=1.0.0
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_subject_name.cn$ value=
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_locale$ value=en
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.dbstatus$ value=NOT_UPDATED
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.requeststatus$ value=begin
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_key$ value=MFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAEy5mzG0XlDtXzr/ZLjoxSzMsQyNvs
AS8Oy93QKFpxYMIOJJwQ5nVLop2kaddoecOegw+Ucy1C7AmSn/wIKj1OnQ==

[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.auth_token.authmgrinstname$ value=CMCUserSignedAuth
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.auth_token.uid$ value=$Unidentified$
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.auth_token.userid$ value=$Unidentified$
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.auth_token.cert_request_type$ value=cmc-crmf
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.profileid$ value=caECFullCMCSelfSignedCert
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.requestid$ value=22
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.auth_token.tokencertsubject$ value=
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.auth_token.authtime$ value=1529077632324
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_x509info$ value=MIIBlKADAgECAgEAMAoGCCqGSM49BAMDMDoxCzAJBgNVBAYTAlVTMRAwDgYDVQQK
EwdDb21wYW55MRkwFwYDVQQDExBDb21wYW55IFJvb3QgQ0EyMB4XDTE4MDYxNTE1
NDcxMloXDTE4MTIxMjE2NDcxMlowHTEbMBkGCgmSJomT8ixkAQETC3Rlc3R1c2Vy
MTAwMFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAEy5mzG0XlDtXzr/ZLjoxSzMsQ
yNvsAS8Oy93QKFpxYMIOJJwQ5nVLop2kaddoecOegw+Ucy1C7AmSn/wIKj1OnaOB
pzCBpDAfBgNVHSMEGDAWgBR0EMvPl3p8ZpXkr5IQNPAlB1ayFjBSBggrBgEFBQcB
AQRGMEQwQgYIKwYBBQUHMAGGNmh0dHA6Ly9ub2NwNC5pZG0ubGFiLmVuZy5yZHUy
LnJlZGhhdC5jb206MjgwODAvY2Evb2NzcDAOBgNVHQ8BAf8EBAMCA9gwHQYDVR0l
BBYwFAYIKwYBBQUHAwIGCCsGAQUFBwME

[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_seq_num$ value=0
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.profilesetid$ value=cmcUserCertSet
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_subject_name.uid$ value=testuser100
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_archive_options$ value=oIIBvDCCAbihHQYJYIZIAWUDBAECBBA25fnwapcg6JmCGFRqa1PRgoIBAQAlSEYo
2fQFL4iOPBtNWOwv6pdXQA8zA6ou3YGzbT8ZtHUxu8oTyI7Grfh65Yguje86Jn4j
wp4F9XxNWksWR7mIx3ortOGSVjrDkPtfxpuphNhWoJkkKrocMAoffVs97z9s7ln/
jYnSphTfShk1+31glHArR8U9ZzlX1aGJEVGC8xwsPwcp+EOXl/wsNnbZklO6yeD0
A3d6OXwwSCdSuqPnaWce7Y1NqlCXC7tPFqVEOO8DWVGCbTk36SumUC+eERSkLk1R
YEWKg4wqjYV9yMt4WtFahPyTtXUHCqnsHXnyo3UZURx98EqtaqI7ih0l6BtDJYpw
Vqy1JKaUFxQYuw/TA4GRABwUPoUIP5LOEYP+E1v5HD9KAkB6+YsFQwgKYeyC2Ekd
o103A5IReI7KPQtRJI6/0DkODTQi5sXaSik2xpHTk9vcD7Kylj+faI5E62MYm5F5
oqN4AopS3QO5bAqQAp0AbDfNBmUwxCGf8jBMFkSNbHkmy5QgcSCCtjQZwNlFVnEL
XzKBtYI49aFuzUJCwAlsJQ==

[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.profileremoteaddr$ value=10.8.60.16
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.requesttype$ value=enrollment
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_extensions$ value=oyEwHzAdBgNVHQ4EFgQUUVAnTQ4B1PQr3Y+IZe20BGFIlno=

[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_transport_cert$ value=MIIDIjCCAqegAwIBAgIBBzAKBggqhkjOPQQDAzA6MQswCQYDVQQGEwJVUzEQMA4GA1UEChMHQ29tcGFueTEZMBcGA1UEAxMQQ29tcGFueSBSb290IENBMjAeFw0xODA2MTUxMjU5MTFaFw0yMDA2MDQxMjU5MTFaMG8xJDAiBgNVBAoMG2V4YW1wbGUuY29tIFNlY3VyaXR5IERvbWFpbjEjMCEGA1UECwwaZ2thcG9vcl9SSENTNzVfa3JhLWVjYy11cDIxIjAgBgNVBAMMGURSTSBUcmFuc3BvcnQgQ2VydGlmaWNhdGUwggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQCohwK3TDFb6iqCn26zx+BN7d/3OC0k4+7OtorOQp7r/RJ+9ctapQy8sPN5l0awRqKo2TZaDz40BCUP1WkWvglVyNTBoZrFqwh4lLdCGZxVeSZv3tAUx4wpT5sDJH6RPXqgahBZaIgkgcj8GOKwQKxmUQREMEFxosbZOxQA7mqQdrJia/N1g03Uv5xBj0CMPpsEiZS9ZnzscBPgwh/VyF29XLyWZp2VhjeMa+6dF1wTyGXH86ZYGm6kTHsbt3vPihIXe2A4KEhcNYnPXXc/HKAuC1jIaObBzS4TXpjjSYfKHkE1o0lQ9KM/6PeoOQQJgGXfWWqcJet0jyk7coORWhsPAgMBAAGjgZ0wgZowHwYDVR0jBBgwFoAUdBDLz5d6fGaV5K+SEDTwJQdWshYwUgYIKwYBBQUHAQEERjBEMEIGCCsGAQUFBzABhjZodHRwOi8vbm9jcDQuaWRtLmxhYi5lbmcucmR1Mi5yZWRoYXQuY29tOjI4MDgwL2NhL29jc3AwDgYDVR0PAQH/BAQDAgTwMBMGA1UdJQQMMAoGCCsGAQUFBwMCMAoGCCqGSM49BAMDA2kAMGYCMQDAlIbZByl/0Vk//ei/M/bC3MnfPvEDADEvzPvPpUYclWJCsAXgz6X353KLGxJN/B8CMQCNYaRoKZ4cnLCpQI3HQg2jKtrQoDzN702ZmB4+x5A9QoLdZ8jUudaW568/W8rAh+A=
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.req_subject_name$ value=MB0xGzAZBgoJkiaJk/IsZAEBEwt0ZXN0dXNlcjEwMA==

[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.bodypartid$ value=1
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: key=$request.profileremotehost$ value=10.8.60.16
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: submit: begins
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: submit: popChallengeRequired =false
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: In LdapBoundConnFactory::getConn()
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: masterConn is connected: true
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: getConn: conn is connected true
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: getConn: mNumConns now 2
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: returnConn: mNumConns now 3
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile: submit:  auth token is not null
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile.validate: start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile.validate: cert subject name:UID=testuser100
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SignedAuditLogger: event PROFILE_CERT_REQUEST
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: BasicProfile: validate start on setId=cmcUserCertSet
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SubjectNameConstraint: validate start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SubjectNameConstraint: validate start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SubjectNameConstraint: validate cert subject =UID=testuser100
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SubjectNameConstraint: validate() - sn500 dname = UID=testuser100
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SubjectNameConstraint: validate end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityConstraint: validate start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityConstraint: not before: Fri Jun 15 11:47:12 EDT 2018
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityConstraint: not after: Wed Dec 12 11:47:12 EST 2018
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityConstraint: range: 365
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityConstraint: range unit: day
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityConstraint: limit: Sat Jun 15 11:47:12 EDT 2019
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: ValidityConstraint: validate end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: KeyConstraint: validate start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: vect: [nistp256, secp256r1]
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: keyParams[i]: 0 param: nistp256
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: KeyConstraint.validate: EC key constrainst passed.
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: KeyConstraint: validate end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: KeyUsageExtConstraint: validate start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: KeyUsageExtConstraint: validate end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SigningAlgConstraint: validate start
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: SigningAlgConstraint: validate end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: BasicProfile: change to pending state
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: BasicProfile: validate end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: EnrollProfile.validate: end
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CAEnrollProfile: execute request ID 22
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CAEnrollProfile: execute found PKIArchiveOptions
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: CAEnrollProfile: execute send request
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: HttpPKIMessage.fromRequest: requestId=22 requestStatus=pending instance=com.netscape.cmscore.request.EnrollmentRequest@305741b2
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: RequestTransfer: profile request id = 22
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: RequestTransfer: attribute size=32
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: Before synch
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: In HttpConnFactory.getConn
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: HttpgetConn: mNumConns now 0
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: HttpConnector.send com.netscape.cmscore.connector.HttpConnection@18a8299e
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: in HttpConnection.send com.netscape.cmscore.connector.HttpConnection@18a8299e
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: writeObject
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: HttpConnection.doSend: with String content length: 6358
[15/Jun/2018:11:47:12][http-bio-28443-exec-10]: HttpConnection: Connecting to nocp4.idm.lab.eng.rdu2.redhat.com:31443 with timeout 30s
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: HttpConnection: Connected to nocp4.idm.lab.eng.rdu2.redhat.com:31443
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: HttpConnection.doSend: sending request
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: HttpConnection.doSend: server returned status 200
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: HttpConnection.send response: got content
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: HttpConn:decoded reply
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: HttpConncter.send has been called
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: reply request id 4
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: reply request type enrollment
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: reply status complete
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: HttpPKMessage.toRequest: requestStatus=pending
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: remote request id 22 was completed
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: In HttpConnFactory.returnConn
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: HttpreturnConn: mNumConns now 1
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: SignedAuditLogger: event SECURITY_DATA_ARCHIVAL_REQUEST
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: LogFile: event type not selected: SECURITY_DATA_ARCHIVAL_REQUEST
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: issueX509Cert
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: dnUTF8Encoding false
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CertificateRepository: getNextSerialNumber  mEnableRandomSerialNumbers=false
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: Repository: in getNextSerialNumber. 
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: Repository: checkRange  mLastSerialNo=17
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: Repository: getNextSerialNumber: returning retSerial 17
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CAService: issueX509Cert: setting issuerDN using exact CA signing cert subjectDN encoding
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: About to ca.sign cert.
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: sign cert get algorithm
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: sign cert encoding cert
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: sign cert encoding algorithm
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CA cert signing: signing cert
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: Getting algorithm context for SHA384withEC ECSignatureWithSHA384Digest
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: Signing Certificate
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: storeX509Cert 17
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: In storeX509Cert
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: In LdapBoundConnFactory::getConn()
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: masterConn is connected: true
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: getConn: conn is connected true
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: getConn: mNumConns now 2
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: returnConn: mNumConns now 3
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: done storeX509Cert
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: SignedAuditLogger: event CERT_REQUEST_PROCESSED
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: In LdapBoundConnFactory::getConn()
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: masterConn is connected: true
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: getConn: conn is connected true
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: getConn: mNumConns now 2
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: returnConn: mNumConns now 3
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: ARequestNotifier  notify mIsPublishingQueueEnabled=false mMaxThreads=1
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: ProfileSubmitCMCServlet: done serving
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CMCOutputTemplate: createFullResponse: begins with cert_request_type=cmc
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CMCOutputTemplate: createFullResponse:  processing cmc
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CMCOutputTemplate: createFullResponse:  error_codes[0]=0
[15/Jun/2018:11:47:13][Thread-16]: RunListeners:: noQueue  SingleRequest
[15/Jun/2018:11:47:13][Thread-16]: RunListeners: IRequestListener = com.netscape.cms.listeners.CertificateIssuedListener
[15/Jun/2018:11:47:13][Thread-16]: CertificateIssuedListener: accept 22
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CMCOutputTemplate: createFullResponse:  processing controls
[15/Jun/2018:11:47:13][Thread-16]: RunListeners: IRequestListener = com.netscape.ca.CRLIssuingPoint$RevocationRequestListener
[15/Jun/2018:11:47:13][Thread-16]: RunListeners: IRequestListener = com.netscape.cms.listeners.CertificateRevokedListener
[15/Jun/2018:11:47:13][Thread-16]: RunListeners:  noQueue  SingleRequest
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CMCOutputTemplate: createFullResponse:  after new ResponseBody, respBody not null
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CMCOutputTemplate: getContentInfo: begins
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CMCOutputTemplate: getContentInfo:  - done
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: SignedAuditLogger: event CMC_RESPONSE_SENT
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CMCOutputTemplate: createFullResponse: ends
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: CMSServlet: curDate=Fri Jun 15 11:47:13 EDT 2018 id=caProfileSubmitCMCFull time=1564
[15/Jun/2018:11:47:13][http-bio-28443-exec-10]: SignedAuditLogger: event ACCESS_SESSION_TERMINATED




Debug logs for KRA


[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: returnConn: mNumConns now 3
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: EnrollmentService: key record 0x4 (UID=testuser100) archived
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: SignedAuditLogger: event SECURITY_DATA_ARCHIVAL_REQUEST_PROCESSED
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: In LdapBoundConnFactory::getConn()
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: masterConn is connected: true
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: getConn: conn is connected true
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: getConn: mNumConns now 2
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: returnConn: mNumConns now 3
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: In LdapBoundConnFactory::getConn()
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: masterConn is connected: true
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: getConn: conn is connected true
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: getConn: mNumConns now 2
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: returnConn: mNumConns now 3
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: ARequestNotifier  notify mIsPublishingQueueEnabled=false mMaxThreads=1
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: SignedAuditLogger: event CERT_REQUEST_PROCESSED
[15/Jun/2018:11:47:13][Thread-15]: RunListeners:: noQueue  SingleRequest
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: LogFile: event type not selected: CERT_REQUEST_PROCESSED
[15/Jun/2018:11:47:13][Thread-15]: RunListeners:  noQueue  SingleRequest
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: HttpPKIMessage.fromRequest: requestId=4 requestStatus=complete instance=com.netscape.cmscore.request.EnrollmentRequest@7066b3c0
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: RequestTransfer: profile request id = 4
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: RequestTransfer: attribute size=35
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: ConnectorServlet: replymsg.reqStatus=complete
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: ConnectorServlet: done requestId=4
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: SignedAuditLogger: event INTER_BOUNDARY
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: LogFile: event type not selected: INTER_BOUNDARY
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: ConnectorServlet: done processRequest
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: writeObject
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: ConnectorServlet: send response RA_Id=CN=Subsystem Certificate,OU=gkapoor-ecc-exca-cmc-ex,O=example.com Security Domain
[15/Jun/2018:11:47:13][http-bio-31443-exec-24]: SignedAuditLogger: event ACCESS_SESSION_TERMINATED



Signed audit for CA

0.http-bio-28443-exec-10 - [15/Jun/2018:11:47:12 EDT] [14] [6] [AuditEvent=ACCESS_SESSION_ESTABLISH][ClientIP=10.8.60.16][ServerIP=10.8.60.16][SubjectID=UID=test10,CN=test10,O=example.org][Outcome=Success] access session establish success
0.http-bio-28443-exec-10 - [15/Jun/2018:11:47:12 EDT] [14] [6] [AuditEvent=AUTHZ][SubjectID=$Unidentified$][Outcome=Success][aclResource=certServer.ee.profile][Op=submit] authorization success
0.http-bio-28443-exec-10 - [15/Jun/2018:11:47:12 EDT] [14] [6] [AuditEvent=CMC_REQUEST_RECEIVED][SubjectID=$Unidentified$][Outcome=Success][CMCRequest=MIIE+QYJKoZIhvcNAQcCoIIE6jCCBOYCAQMxDzANBglghkgBZQMEAgEFADCCA/sGCCsGAQUFBwwCoIID7QSCA+kwggPlMIG6MFECAQEGCCsGAQUFBwcWMUIEQNssIpdWU7Q/wOJ71iswL22BcsTKUdJLZ063agJlvWumqoqdNJ4gQMuUdMIGKoPu0t8AlRcudt/+FJ1HbLC+wKYwFwIBAQYIKwYBBQUHBwIxCAwGdXNlcjNhMEwCAQIGCCsGAQUFBwciMT0wOzALBglghkgBZQMEAgMwCgYIKoZIhvcNAgkEILwP5vZd2a/9W6AINuSvFuR2BABZYlKyHyVhMj+XklMVMIIDIKGCAxwwggLAAgEBMIGegAECpR8wHTEbMBkGCgmSJomT8ixkAQETC3Rlc3R1c2VyMTAwplkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAEy5mzG0XlDtXzr/ZLjoxSzMsQyNvsAS8Oy93QKFpxYMIOJJwQ5nVLop2kaddoecOegw+Ucy1C7AmSn/wIKj1OnakdMBsGA1UdDgQUUVAnTQ4B1PQr3Y+IZe20BGFIlnowggIYMIIBywYJKwYBBQUHBQEEoIIBvDCCAbihHQYJYIZIAWUDBAECBBA25fnwapcg6JmCGFRqa1PRgoIBAQAlSEYo2fQFL4iOPBtNWOwv6pdXQA8zA6ou3YGzbT8ZtHUxu8oTyI7Grfh65Yguje86Jn4jwp4F9XxNWksWR7mIx3ortOGSVjrDkPtfxpuphNhWoJkkKrocMAoffVs97z9s7ln/jYnSphTfShk1+31glHArR8U9ZzlX1aGJEVGC8xwsPwcp+EOXl/wsNnbZklO6yeD0A3d6OXwwSCdSuqPnaWce7Y1NqlCXC7tPFqVEOO8DWVGCbTk36SumUC+eERSkLk1RYEWKg4wqjYV9yMt4WtFahPyTtXUHCqnsHXnyo3UZURx98EqtaqI7ih0l6BtDJYpwVqy1JKaUFxQYuw/TA4GRABwUPoUIP5LOEYP+E1v5HD9KAkB6+YsFQwgKYeyC2Ekdo103A5IReI7KPQtRJI6/0DkODTQi5sXaSik2xpHTk9vcD7Kylj+faI5E62MYm5F5oqN4AopS3QO5bAqQAp0AbDfNBmUwxCGf8jBMFkSNbHkmy5QgcSCCtjQZwNlFVnELXzKBtYI49aFuzUJCwAlsJTBHBggrBgEFBQcHITA7MAsGCWCGSAFlAwQCATAKBggqhkiG9w0CCQQgMH7RZ4Qid3ZXwtfmvWTUEzspQ9I55cgYbfqn+KhoR6mhVjAKBggqhkjOPQQDAgNIADBFAiEApK09k/9HVDwFblX51kzamWRQxVoaO2MZL+ltW9GjQYkCIAQVAD9CT0TdeJSIx+moCMRVn5lnnrrw6htJ1zOn6uCMMAAwAKAAMYHOMIHLAgEDgBRRUCdNDgHU9Cvdj4hl7bQEYUiWejANBglghkgBZQMEAgEFAKBKMBcGCSqGSIb3DQEJAzEKBggrBgEFBQcMAjAvBgkqhkiG9w0BCQQxIgQgrIVA8xghAZQkz6jtpagAzwQ3HVnksXsxjSsd/1VZqFgwDAYIKoZIzj0EAwIFAARHMEUCIQC4Xv+ItI9a47QNlzhX63d/sO3ipbmL68tBvaZ3nGb4iQIgBkOcUJHprUBcaDXOjQUVo/9IRs0oFf46CDu0YZ2TOzg=] CMC request received
0.http-bio-28443-exec-10 - [15/Jun/2018:11:47:12 EDT] [14] [6] [AuditEvent=PROOF_OF_POSSESSION][SubjectID=user3a][Outcome=Success][Info=method=EnrollProfile: verifyPOP: ] proof of possession
0.http-bio-28443-exec-10 - [15/Jun/2018:11:47:12 EDT] [14] [6] [AuditEvent=PROFILE_CERT_REQUEST][SubjectID=user3a][Outcome=Success][ReqID=22][ProfileID=caECFullCMCSelfSignedCert][CertSubject=UID=testuser100] certificate request made with certificate profiles
0.http-bio-28443-exec-10 - [15/Jun/2018:11:47:13 EDT] [14] [6] [AuditEvent=CERT_REQUEST_PROCESSED][SubjectID=$Unidentified$][Outcome=Success][ReqID=22][CertSerialNum=17] certificate request processed
0.http-bio-28443-exec-10 - [15/Jun/2018:11:47:13 EDT] [14] [6] [AuditEvent=CMC_RESPONSE_SENT][SubjectID=user3a][Outcome=Success][CMCResponse=MIIJEgYJKoZIhvcNAQcCoIIJAzCCCP8CAQMxDzANBglghkgBZQMEAgIFADAxBggrBgEFBQcMA6AlBCMwITAbMBkCAQEGCCsGAQUFBwcZMQowCAIBADADAgEBMAAwAKCCB1YwggIPMIIBlKADAgECAgERMAoGCCqGSM49BAMDMDoxCzAJBgNVBAYTAlVTMRAwDgYDVQQKEwdDb21wYW55MRkwFwYDVQQDExBDb21wYW55IFJvb3QgQ0EyMB4XDTE4MDYxNTE1NDcxMloXDTE4MTIxMjE2NDcxMlowHTEbMBkGCgmSJomT8ixkAQETC3Rlc3R1c2VyMTAwMFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAEy5mzG0XlDtXzr/ZLjoxSzMsQyNvsAS8Oy93QKFpxYMIOJJwQ5nVLop2kaddoecOegw+Ucy1C7AmSn/wIKj1OnaOBpzCBpDAfBgNVHSMEGDAWgBR0EMvPl3p8ZpXkr5IQNPAlB1ayFjBSBggrBgEFBQcBAQRGMEQwQgYIKwYBBQUHMAGGNmh0dHA6Ly9ub2NwNC5pZG0ubGFiLmVuZy5yZHUyLnJlZGhhdC5jb206MjgwODAvY2Evb2NzcDAOBgNVHQ8BAf8EBAMCA9gwHQYDVR0lBBYwFAYIKwYBBQUHAwIGCCsGAQUFBwMEMAoGCCqGSM49BAMDA2kAMGYCMQCZE9VkS+INhR33ChHgBDBsf+ty2dNbqzyFtx26CVay78pxuyfH0SR4UIVyCVb+34kCMQCbmp3K2/3RShNmQdey59Re/RKdQ1SasXLpZdcq7oJzcgVE+DdrdtjRAzebQ/0UxQYwggKIMIICDqADAgECAgQG0t0hMAoGCCqGSM49BAMDMGYxHjAcBgNVBAoMFUV4YW1wbGUtcmhjczkyLUNBLWVjYzEjMCEGA1UECwwaZ2thcG9vcl9SSENTNzVfdXBkYXRlMl9lY2MxHzAdBgNVBAMMFkNBIFNpZ25pbmcgQ2VydGlmaWNhdGUwHhcNMTgwNjEzMTY1NDExWhcNMzgwMzA1MTc1NDExWjA6MQswCQYDVQQGEwJVUzEQMA4GA1UEChMHQ29tcGFueTEZMBcGA1UEAxMQQ29tcGFueSBSb290IENBMjB2MBAGByqGSM49AgEGBSuBBAAiA2IABHOWGZ6m6jFISsSlgzdbMO6C6F9usn14iKEw9G2Zo0DPhr1HSglsZhJI/vxEAM//AUINhcyJUzxGkv1ftFqRuvrhTuKTAMhRT1Lx9gGJBO3GVZ+jCysp8oHpcXBNqwTOzqOBuDCBtTAfBgNVHSMEGDAWgBQuk8VRXk5A+iq3vqqIxi/dHAG/fjAPBgNVHRMBAf8EBTADAQH/MA4GA1UdDwEB/wQEAwIBxjAdBgNVHQ4EFgQUdBDLz5d6fGaV5K+SEDTwJQdWshYwUgYIKwYBBQUHAQEERjBEMEIGCCsGAQUFBzABhjZodHRwOi8vbm9jcDQuaWRtLmxhYi5lbmcucmR1Mi5yZWRoYXQuY29tOjIwMDgwL2NhL29jc3AwCgYIKoZIzj0EAwMDaAAwZQIxALbOB1JYbxPSfJnzHwfJEg2ogsuTBHeSEcORVyaBrk1tNHKUIu15PFGKjDiKRx4BtAIwHSi8JtGjJo2n8SCkgXrXEcFOYuq0YfAHioRpqqFdEymrruxhrd2wxywmkteGZGadMIICszCCAjqgAwIBAgIEBdDGmDAKBggqhkjOPQQDAzBmMR4wHAYDVQQKDBVFeGFtcGxlLXJoY3M5Mi1DQS1lY2MxIzAhBgNVBAsMGmdrYXBvb3JfUkhDUzc1X3VwZGF0ZTJfZWNjMR8wHQYDVQQDDBZDQSBTaWduaW5nIENlcnRpZmljYXRlMB4XDTE4MDUyNTEwMzMyN1oXDTM4MDUyNTEwMzMyN1owZjEeMBwGA1UECgwVRXhhbXBsZS1yaGNzOTItQ0EtZWNjMSMwIQYDVQQLDBpna2Fwb29yX1JIQ1M3NV91cGRhdGUyX2VjYzEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZTB2MBAGByqGSM49AgEGBSuBBAAiA2IABObj2RAcm9/fS5wQet/ithLdKvmfQEkjGJcX12wXADQVmdicLU4WY8mdknG0uOol14S178FrR0EfPZbVmhBChKPbpSn4ILN2bN0NR1MvjX2jaLBrFwtexkVn+whPXnzkE6OBuDCBtTAfBgNVHSMEGDAWgBQuk8VRXk5A+iq3vqqIxi/dHAG/fjAPBgNVHRMBAf8EBTADAQH/MA4GA1UdDwEB/wQEAwIBxjAdBgNVHQ4EFgQULpPFUV5OQPoqt76qiMYv3RwBv34wUgYIKwYBBQUHAQEERjBEMEIGCCsGAQUFBzABhjZodHRwOi8vbm9jcDQuaWRtLmxhYi5lbmcucmR1Mi5yZWRoYXQuY29tOjIwMDgwL2NhL29jc3AwCgYIKoZIzj0EAwMDZwAwZAIwRtWeH6EbCbfMOzD20bGl+awlHGuFRwYpBbwG/u7MCYywcTeTQvmsEfOuB8TvsADhAjBPyQi1xvgLrElfjmzh6VTfXi4xqNi2bYJJELG9ZPh2L1PhpAy3a02jrEH9UNM4S9UxggFaMIIBVgIBATBuMGYxHjAcBgNVBAoMFUV4YW1wbGUtcmhjczkyLUNBLWVjYzEjMCEGA1UECwwaZ2thcG9vcl9SSENTNzVfdXBkYXRlMl9lY2MxHzAdBgNVBAMMFkNBIFNpZ25pbmcgQ2VydGlmaWNhdGUCBAbS3SEwDQYJYIZIAWUDBAICBQCgWjAXBgkqhkiG9w0BCQMxCgYIKwYBBQUHDAMwPwYJKoZIhvcNAQkEMTIEMEem8h5SGlF1pQCzfM+7OZRKcXqqv6vAgePVzmvT+kvcLoZxZWR01B+qrvUTmwodUjAMBggqhkjOPQQDAwUABGgwZgIxAOTV/O7MJs++lROnNOv6T+rA3Fdnfd2v+UFyVPDDQhRuXgj+3AEb3KWvI1azZ3YfKQIxAPTIGuMZ91tf9MOpr+03AG9TMQLX15/dLb5QB+XATnXhvUnY+PNv6YCi3t+cDDyK9A==] CMC response sent
0.http-bio-28443-exec-10 - [15/Jun/2018:11:47:13 EDT] [14] [6] [AuditEvent=ACCESS_SESSION_TERMINATED][ClientIP=10.8.60.16][ServerIP=10.8.60.16][SubjectID=UID=test10,CN=test10,O=example.org][Outcome=Success][Info=CLOSE_NOTIFY] access session terminated





Signed audit for KRA

0.http-bio-31443-exec-24 - [15/Jun/2018:11:47:13 EDT] [14] [6] [AuditEvent=ACCESS_SESSION_ESTABLISH][ClientIP=10.8.60.16][ServerIP=10.8.60.16][SubjectID=CN=Subsystem Certificate,OU=gkapoor-ecc-exca-cmc-ex,O=example.com Security Domain][Outcome=Success] access session establish success
0.http-bio-31443-exec-24 - [15/Jun/2018:11:47:13 EDT] [14] [6] [AuditEvent=AUTH][SubjectID=CA-nocp4.idm.lab.eng.rdu2.redhat.com-28443][Outcome=Success][AuthMgr=certUserDBAuthMgr] authentication success
0.http-bio-31443-exec-24 - [15/Jun/2018:11:47:13 EDT] [14] [6] [AuditEvent=AUTHZ][SubjectID=CA-nocp4.idm.lab.eng.rdu2.redhat.com-28443][Outcome=Success][aclResource=certServer.kra.connector][Op=submit] authorization success
0.http-bio-31443-exec-24 - [15/Jun/2018:11:47:13 EDT] [14] [6] [AuditEvent=ROLE_ASSUME][SubjectID=CA-nocp4.idm.lab.eng.rdu2.redhat.com-28443][Outcome=Success][Role=Trusted Managers] assume privileged role
0.http-bio-31443-exec-24 - [15/Jun/2018:11:47:13 EDT] [14] [6] [AuditEvent=PROFILE_CERT_REQUEST][SubjectID=CA-nocp4.idm.lab.eng.rdu2.redhat.com-28443][Outcome=Success][ReqID=22][ProfileID=kraConnector][CertSubject=UID=testuser100] certificate request made with certificate profiles
0.http-bio-31443-exec-24 - [15/Jun/2018:11:47:13 EDT] [14] [6] [AuditEvent=ACCESS_SESSION_TERMINATED][ClientIP=10.8.60.16][ServerIP=10.8.60.16][SubjectID=CN=Subsystem Certificate,OU=gkapoor-ecc-exca-cmc-ex,O=example.com Security Domain][Outcome=Success][Info=CLOSE_NOTIFY] access session terminated




Verification 2: Check KRA agent page if archival happens.

1 	complete 		UID=testuser
2 	complete 		UID=testuser
3 	complete 		UID=testuser1
4 	complete 		UID=testuser100

Request 4
Request
Status:	complete
Type:	enrollment
Created on:	6/15/2018, 9:17:13 PM
Updated by:	CA-nocp4.idm.lab.eng.rdu2.redhat.com-28443
Updated on:	6/15/2018, 9:17:13 PM
Archival Information
Public key:	30:59:30:13:06:07:2A:86:48:CE:3D:02:01:06:08:2A:86:48:CE:3D: 03:01:07:03:42:00:04:CB:99:B3:1B:45:E5:0E:D5:F3:AF:F6:4B:8E: 8C:52:CC:CB:10:C8:DB:EC:01:2F:0E:CB:DD:D0:28:5A:71:60:C2:0E: 24:9C:10:E6:75:4B:A2:9D:A4:69:D7:68:79:C3:9E:83:0F:94:73:2D: 42:EC:09:92:9F:FC:08:2A:3D:4E:9D
Owner name:	UID=testuser100
Key identifier:	4
Comment 11 errata-xmlrpc 2018-06-26 16:47:58 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2018:1979
Comment 13 Red Hat Bugzilla 2023-09-15 01:26:54 UTC 
The needinfo request[s] on this closed bug have been removed as they have been unresolved for 365 days