RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1525306 - CC: missing CMC request and response record
Summary: CC: missing CMC request and response record
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: pki-core
Version: 7.5
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: Christina Fu
QA Contact: Asha Akkiangady
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-12-13 02:33 UTC by Christina Fu
Modified: 2020-10-04 21:38 UTC (History)
5 users (show)

Fixed In Version: pki-core-10.5.1-7.el7
Doc Type: No Doc Update
Doc Text:
https://bugzilla.redhat.com/show_bug.cgi?id=1518180#c7
Clone Of:
Environment:
Last Closed: 2018-04-10 17:02:54 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github dogtagpki pki issues 2999 0 None None None 2020-10-04 21:38:53 UTC
Red Hat Product Errata RHBA-2018:0925 0 None None None 2018-04-10 17:03:37 UTC

Description Christina Fu 2017-12-13 02:33:49 UTC 
this came up in ST review.  for FIA_CMCS_EXT.1, it is required to store signed CMC requests received, and signed CMC responses sent.
RHCS currently does not literally record the actual signed CMC requests and responses.  I have verified with Gossamer that we CAN do either of the following:
* Logged as audit events.
* Recorded into corresponding request records.
I specifically asked for this because it would seem more useful to save the CMC requests in the request records instead.
Comment 3 Christina Fu 2018-02-03 01:31:04 UTC 
https://pagure.io/dogtagpki/issue/2880#comment-491898
Comment 5 Geetika Kapoor 2018-02-15 11:25:40 UTC 
Test Case 1 : Perform an operation and check audit logs for CMC
Verification: Make sure CMC_REQUEST_RECEIVED and CMC_RESPONSE_SENT exist. However subjectid is still unidentified.Is it okay to have like that?


0.http-bio-25443-exec-3 - [15/Feb/2018:05:44:49 EST] [14] [6] [AuditEvent=ACCESS_SESSION_ESTABLISH][ClientIP=10.12.28.208][ServerIP=10.12.28.208][SubjectID=UID=sslauth,OU=People][Outcome=Success] access session establish success
0.http-bio-25443-exec-3 - [15/Feb/2018:05:44:49 EST] [14] [6] [AuditEvent=AUTHZ][SubjectID=$Unidentified$][Outcome=Success][aclResource=certServer.ee.profile][Op=submit] authorization success
0.http-bio-25443-exec-3 - [15/Feb/2018:05:44:49 EST] [14] [6] [AuditEvent=CMC_REQUEST_RECEIVED][SubjectID=$Unidentified$][Outcome=Success][CMCRequest=MIG7BgkqhkiG9w0BBwGgga0EgaowgacwgZ4wgZsCAQEGCCsGAQUFBwcRMYGLMIGIMFYxFTATBgNVBAoMDFNFQ3VyZS1Ec09PTzEcMBoGA1UECwwTZ2thcG9vcl9SSENTXzc1X3NzbDEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZQIECGnKhAoBBgQMd29uZGVyZnVsZGF5DBdnZWV0aWthIHRlc3QgcmV2b2NhdGlvbjAAMAAwAA==] CMC request received
0.http-bio-25443-exec-3 - [15/Feb/2018:05:44:49 EST] [14] [6] [AuditEvent=CMC_RESPONSE_SENT][SubjectID=$Unidentified$][Outcome=Success][CMCResponse=MIIGPwYJKoZIhvcNAQcCoIIGMDCCBiwCAQMxDzANBglghkgBZQMEAgMFADA0BggrBgEFBQcMA6AoBCYwJDAeMBwCAQEGCCsGAQUFBwcZMQ0wCwIBAjADAgEBAgEHMAAwAKCCA+gwggPkMIICzKADAgECAgQM3QwgMA0GCSqGSIb3DQEBDQUAMFMxEjAQBgNVBAoMCVNFQ3VyZS1EczEcMBoGA1UECwwTZ2thcG9vcl9SSENTXzc1X3NzbDEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZTAeFw0xODAyMTExOTE4MjlaFw0zODAyMTExOTE4MjlaMFMxEjAQBgNVBAoMCVNFQ3VyZS1EczEcMBoGA1UECwwTZ2thcG9vcl9SSENTXzc1X3NzbDEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZTCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBAJRuy2MpwSogHtg84aBToFzWzZmkqCdIlO363KqhGb9SDI7nYdJWfSuMW3sMpdxeP/E9DqaEgiTw1b3OBTxSojLHbcjzAiT4iRNv2kwZwMit7JmfemVWMHCwoGm80qrUwUoIcau/I86HXrGN6BjTzjHQJHMbefH+I2zqh0bXhcLCvfH/Vg4X39eQ1Fp/xtX2E8SvjgBagvFVMcUw9XCPk4Gn7i6TTY4fgqq7qqZqrsVNziA2NL07BqvX9joCI3RzJwnxzVP1r8fBA9sPLHrkYUxue/ObQo2uRL91OYdI3R4HLJilbrgYWrixziDXPr6UrbEsiEE+rSg4ff+0yBoGT78CAwEAAaOBvzCBvDAfBgNVHSMEGDAWgBRexDUJbLEkPOUGRug4ZhxMlYyjRjAPBgNVHRMBAf8EBTADAQH/MA4GA1UdDwEB/wQEAwIBxjAdBgNVHQ4EFgQUXsQ1CWyxJDzlBkboOGYcTJWMo0YwWQYIKwYBBQUHAQEETTBLMEkGCCsGAQUFBzABhj1odHRwOi8vY3NxYTQtZ3Vlc3QwNC5pZG0ubGFiLmVuZy5yZHUucmVkaGF0LmNvbToyNTA4MC9jYS9vY3NwMA0GCSqGSIb3DQEBDQUAA4IBAQBV+JNL9Gpm88yTiWPdJgHpiXVQusKJIchrRBTFA1ZbBTFJTcsjv5XrdvEGS4X5PcO6xzWxFLKiiS7T6LA0g6ghVubwqcHo3tmj+xHxNhVopwa9TxvXEPNwfnBFluUwRMoDy1ULb4/ohplmeGVkEeNLfTyo0xtpBSMj92iy6ZwYw5dmE0ZFxfx6hzUnk65qn8H2mIdnWHiRjkwQGCdrq2oizcVM0OaX5rz0msgqSWFO85XjX/IxPVJJNNixSgSFIirVLToModCqX2puWn4wermn8INI3k8MMPOxpEK6L6IFEfGUqXEr/YnRgAGrPljw39p2wU/SCnp8P8CVzIssi/x0MYIB8jCCAe4CAQEwWzBTMRIwEAYDVQQKDAlTRUN1cmUtRHMxHDAaBgNVBAsME2drYXBvb3JfUkhDU183NV9zc2wxHzAdBgNVBAMMFkNBIFNpZ25pbmcgQ2VydGlmaWNhdGUCBAzdDCAwDQYJYIZIAWUDBAIDBQCgajAXBgkqhkiG9w0BCQMxCgYIKwYBBQUHDAMwTwYJKoZIhvcNAQkEMUIEQEvv2Hre+zYecA1BQPgG1/2oiSly9W6NdK7+dN9RxLwLiAyPnTYH/6v+5z4bW4rdVvzS+N6RWR5fhCwr7OIr37EwDQYJKoZIhvcNAQENBQAEggEAK+9OkkkDSE+652cRCEQYBNwO6iLXbOGoVWas5ahTqvMLlSAYOTD8PVOrJvkTKcCyUQXMQc3SbGTurVFPL7o8PFwJ05jou0DmG3o4J6/Djbf+Gt0QVPW/tVwN4x49JrRB3LJXRv/EQU8EGn85/hYgcrLJMwUJzMnu5aeoilbotAItwzj6sFezHFCqTwu9aHWFYGlU07IAZJL/6LGX5q8V0iuU9eK92K2PuK3pH0Ya5KIWIWKg0igSgBZt6e4PkznU2ln7Am5hTrfM23EsvHOU7cBwIJHLVSotzj1fwkPO7rf7cOY1CCFjprjsJqj3qlhQN7WTpsPX1nPZkrmgVodYtg==] CMC response sent
0.http-bio-25443-exec-3 - [15/Feb/2018:05:44:49 EST] [14] [6] [AuditEvent=ACCESS_SESSION_TERMINATED][ClientIP=10.12.28.208][ServerIP=10.12.28.208][SubjectID=UID=sslauth,OU=People][Outcome=Success][Info=CLOSE_NOTIFY] access session terminated
Comment 6 Christina Fu 2018-02-15 18:30:19 UTC 
Again, whether subjectID contains anything meaningful or not depends on what type of authentication was used and whether at the point of the audit event the info is available or not.
Although looking at the events there in comment #5
[AuditEvent=ACCESS_SESSION_ESTABLISH][ClientIP=10.12.28.208][ServerIP=10.12.28.208][SubjectID=UID=sslauth,OU=People][Outcome=Success] access session establish success
The above event suggests that this was an SSL client authentication?

If so then I think the SubjectID should be carried throughout the rest of the operations.
Please include your test steps and config etc. when reporting issues so we don't have to guess. thanks.
Comment 7 Geetika Kapoor 2018-02-20 13:05:50 UTC 
Hi christina,

I am able to get the the behavior as mentioned in https://bugzilla.redhat.com/show_bug.cgi?id=1525306#c5 in below scenario.

Setup:
-----

1. I am trying to revoke a certificate.
2. I am using incorrect revRequest.sharedSecret=wonderfulday12345.
Correct value is revRequest.sharedSecret=wonderfulday.
3. In this case debug logs shows:

[20/Feb/2018:08:01:38][http-bio-25443-exec-11]: SharedSecret.decryptShrTokData: wrapped session key retrieved
[20/Feb/2018:08:01:38][http-bio-25443-exec-11]: SharedSecret.decryptShrTokData: wrapped passphrase retrieved
[20/Feb/2018:08:01:38][http-bio-25443-exec-11]: SharedSecret.getSharedToken(BigInteger serial): returning
[20/Feb/2018:08:01:38][http-bio-25443-exec-11]: CMCOutputTemplate: processRevokeRequestControl:  Client and server shared secret are not the same, cannot revoke certificate.
[20/Feb/2018:08:01:38][http-bio-25443-exec-11]: SignedAuditLogger: event CERT_STATUS_CHANGE_REQUEST_PROCESSED
[20/Feb/2018:08:01:38][http-bio-25443-exec-11]: LogFile: event type not selected: CERT_STATUS_CHANGE_REQUEST_PROCESSED


4. Audit logs :

0.http-bio-25443-exec-11 - [20/Feb/2018:08:01:38 EST] [14] [6] [AuditEvent=ACCESS_SESSION_ESTABLISH][ClientIP=10.12.28.208][ServerIP=10.12.28.208][SubjectID=UID=sslauth,OU=People][Outcome=Success] access session establish success
0.http-bio-25443-exec-11 - [20/Feb/2018:08:01:38 EST] [14] [6] [AuditEvent=AUTHZ][SubjectID=$Unidentified$][Outcome=Success][aclResource=certServer.ee.profile][Op=submit] authorization success
0.http-bio-25443-exec-11 - [20/Feb/2018:08:01:38 EST] [14] [6] [AuditEvent=CMC_REQUEST_RECEIVED][SubjectID=$Unidentified$][Outcome=Success][CMCRequest=MIG9BgkqhkiG9w0BBwGgga8EgawwgakwgaAwgZ0CAQEGCCsGAQUFBwcRMYGNMIGKMFMxEjAQBgNVBAoMCVNFQ3VyZS1EczEcMBoGA1UECwwTZ2thcG9vcl9SSENTXzc1X3NzbDEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZQIECGnKhAoBBgQRd29uZGVyZnVsZGF5MTIzNDUMF2dlZXRpa2EgdGVzdCByZXZvY2F0aW9uMAAwADAA] CMC request received
0.http-bio-25443-exec-11 - [20/Feb/2018:08:01:38 EST] [14] [6] [AuditEvent=CMC_RESPONSE_SENT][SubjectID=$Unidentified$][Outcome=Success][CMCResponse=MIIGPwYJKoZIhvcNAQcCoIIGMDCCBiwCAQMxDzANBglghkgBZQMEAgMFADA0BggrBgEFBQcMA6AoBCYwJDAeMBwCAQEGCCsGAQUFBwcZMQ0wCwIBAjADAgEBAgEHMAAwAKCCA+gwggPkMIICzKADAgECAgQM3QwgMA0GCSqGSIb3DQEBDQUAMFMxEjAQBgNVBAoMCVNFQ3VyZS1EczEcMBoGA1UECwwTZ2thcG9vcl9SSENTXzc1X3NzbDEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZTAeFw0xODAyMTExOTE4MjlaFw0zODAyMTExOTE4MjlaMFMxEjAQBgNVBAoMCVNFQ3VyZS1EczEcMBoGA1UECwwTZ2thcG9vcl9SSENTXzc1X3NzbDEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZTCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBAJRuy2MpwSogHtg84aBToFzWzZmkqCdIlO363KqhGb9SDI7nYdJWfSuMW3sMpdxeP/E9DqaEgiTw1b3OBTxSojLHbcjzAiT4iRNv2kwZwMit7JmfemVWMHCwoGm80qrUwUoIcau/I86HXrGN6BjTzjHQJHMbefH+I2zqh0bXhcLCvfH/Vg4X39eQ1Fp/xtX2E8SvjgBagvFVMcUw9XCPk4Gn7i6TTY4fgqq7qqZqrsVNziA2NL07BqvX9joCI3RzJwnxzVP1r8fBA9sPLHrkYUxue/ObQo2uRL91OYdI3R4HLJilbrgYWrixziDXPr6UrbEsiEE+rSg4ff+0yBoGT78CAwEAAaOBvzCBvDAfBgNVHSMEGDAWgBRexDUJbLEkPOUGRug4ZhxMlYyjRjAPBgNVHRMBAf8EBTADAQH/MA4GA1UdDwEB/wQEAwIBxjAdBgNVHQ4EFgQUXsQ1CWyxJDzlBkboOGYcTJWMo0YwWQYIKwYBBQUHAQEETTBLMEkGCCsGAQUFBzABhj1odHRwOi8vY3NxYTQtZ3Vlc3QwNC5pZG0ubGFiLmVuZy5yZHUucmVkaGF0LmNvbToyNTA4MC9jYS9vY3NwMA0GCSqGSIb3DQEBDQUAA4IBAQBV+JNL9Gpm88yTiWPdJgHpiXVQusKJIchrRBTFA1ZbBTFJTcsjv5XrdvEGS4X5PcO6xzWxFLKiiS7T6LA0g6ghVubwqcHo3tmj+xHxNhVopwa9TxvXEPNwfnBFluUwRMoDy1ULb4/ohplmeGVkEeNLfTyo0xtpBSMj92iy6ZwYw5dmE0ZFxfx6hzUnk65qn8H2mIdnWHiRjkwQGCdrq2oizcVM0OaX5rz0msgqSWFO85XjX/IxPVJJNNixSgSFIirVLToModCqX2puWn4wermn8INI3k8MMPOxpEK6L6IFEfGUqXEr/YnRgAGrPljw39p2wU/SCnp8P8CVzIssi/x0MYIB8jCCAe4CAQEwWzBTMRIwEAYDVQQKDAlTRUN1cmUtRHMxHDAaBgNVBAsME2drYXBvb3JfUkhDU183NV9zc2wxHzAdBgNVBAMMFkNBIFNpZ25pbmcgQ2VydGlmaWNhdGUCBAzdDCAwDQYJYIZIAWUDBAIDBQCgajAXBgkqhkiG9w0BCQMxCgYIKwYBBQUHDAMwTwYJKoZIhvcNAQkEMUIEQEvv2Hre+zYecA1BQPgG1/2oiSly9W6NdK7+dN9RxLwLiAyPnTYH/6v+5z4bW4rdVvzS+N6RWR5fhCwr7OIr37EwDQYJKoZIhvcNAQENBQAEggEAK+9OkkkDSE+652cRCEQYBNwO6iLXbOGoVWas5ahTqvMLlSAYOTD8PVOrJvkTKcCyUQXMQc3SbGTurVFPL7o8PFwJ05jou0DmG3o4J6/Djbf+Gt0QVPW/tVwN4x49JrRB3LJXRv/EQU8EGn85/hYgcrLJMwUJzMnu5aeoilbotAItwzj6sFezHFCqTwu9aHWFYGlU07IAZJL/6LGX5q8V0iuU9eK92K2PuK3pH0Ya5KIWIWKg0igSgBZt6e4PkznU2ln7Am5hTrfM23EsvHOU7cBwIJHLVSotzj1fwkPO7rf7cOY1CCFjprjsJqj3qlhQN7WTpsPX1nPZkrmgVodYtg==] CMC response sent
0.http-bio-25443-exec-11 - [20/Feb/2018:08:01:38 EST] [14] [6] [AuditEvent=ACCESS_SESSION_TERMINATED][ClientIP=10.12.28.208][ServerIP=10.12.28.208][SubjectID=UID=sslauth,OU=People][Outcome=Success][Info=CLOSE_NOTIFY] access session terminated
Comment 8 Geetika Kapoor 2018-02-20 13:14:53 UTC 
Sorry I missed to  reply for your question, ssl auth is successful because certificate used is correct in HttpClient.
Comment 9 Christina Fu 2018-02-22 23:25:20 UTC 
The client failed the shared secret check so we cannot identify the client.
So as far as this bug goes, the CMC_REQUEST_RECEIVED and CMC_RESPONSE_SENT look correct.

There should be a "CMC_PROOF_OF_IDENTIFICATION" event to record the attempted credential though.  If that's missing then it's a bug.  But it's a different bug. Are you sure CMC_PROOF_OF_IDENTIFICATION not in your audit log when shared token failed?
Comment 10 Geetika Kapoor 2018-02-23 06:02:45 UTC 
Hi Christina,

I didn't find that event neither in audit logs nor debug logs. Here is the snip:

I re-run the test again:

debug logs:
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: EnrollProfile: parseCMC: pre-signed CMC request; no further proof of identification check
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: EnrollProfile: parseCMC: found numOfOtherMsgs: 0
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: EnrollProfile: parseCMC: getting :cmc.popLinkWitnessRequired
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: EnrollProfile: parseCMC: popLinkWitness(V2) not required
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: EnrollProfile: parseCMC: nummsgs 0; returning...
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: EnrollProfile: createRequests: parseCMC returns cmc_msgs null
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: ProfileSubmitCMCServlet: revocation request
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: ProfileSubmitCMCServlet: done serving
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: createFullResponse: begins with cert_request_type=cmc
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: createFullResponse:  processing cmc
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: createFullResponse:  reqs null. could be revocation
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: createFullResponse:  processing controls
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: processRevokeRequestControl: begins
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: processRevokeRequestControl: authManagerId =CMCUserSignedAuth
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: processRevokeRequestControl: checking shared secret
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: In LdapBoundConnFactory::getConn()
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: masterConn is connected: true
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: getConn: conn is connected true
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: getConn: mNumConns now 2
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: returnConn: mNumConns now 3
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: SharedSecret.decryptShrTokData: wrapped session key retrieved
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: SharedSecret.decryptShrTokData: wrapped passphrase retrieved
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: SharedSecret.getSharedToken(BigInteger serial): returning
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: processRevokeRequestControl:  Client and server shared secret are not the same, cannot revoke certificate.
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: SignedAuditLogger: event CERT_STATUS_CHANGE_REQUEST_PROCESSED
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: LogFile: event type not selected: CERT_STATUS_CHANGE_REQUEST_PROCESSED
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: createFullResponse:  after new ResponseBody, respBody not null
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: getContentInfo: begins
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: getContentInfo:  - done
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: SignedAuditLogger: event CMC_RESPONSE_SENT
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMCOutputTemplate: createFullResponse: ends
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: CMSServlet: curDate=Fri Feb 23 00:19:55 EST 2018 id=caProfileSubmitUserSignedCMCFull time=196
[23/Feb/2018:00:19:55][http-bio-25443-exec-1]: SignedAuditLogger: event ACCESS_SESSION_TERMINATED

Audit logs:

0.http-bio-25443-exec-1 - [23/Feb/2018:00:19:54 EST] [14] [6] [AuditEvent=ACCESS_SESSION_ESTABLISH][ClientIP=10.12.28.208][ServerIP=10.12.28.208][SubjectID=CN=Certecc,UID=Testing][Outcome=Success] access session establish success
0.http-bio-25443-exec-1 - [23/Feb/2018:00:19:55 EST] [14] [6] [AuditEvent=AUTHZ][SubjectID=$Unidentified$][Outcome=Success][aclResource=certServer.ee.profile][Op=submit] authorization success
0.http-bio-25443-exec-1 - [23/Feb/2018:00:19:55 EST] [14] [6] [AuditEvent=CMC_REQUEST_RECEIVED][SubjectID=$Unidentified$][Outcome=Success][CMCRequest=MIG9BgkqhkiG9w0BBwGgga8EgawwgakwgaAwgZ0CAQEGCCsGAQUFBwcRMYGNMIGKMFMxEjAQBgNVBAoMCVNFQ3VyZS1EczEcMBoGA1UECwwTZ2thcG9vcl9SSENTXzc1X3NzbDEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZQIECGnKhAoBBgQRd29uZGVyZnVsZGF5MTIzNDUMF2dlZXRpa2EgdGVzdCByZXZvY2F0aW9uMAAwADAA] CMC request received
0.http-bio-25443-exec-1 - [23/Feb/2018:00:19:55 EST] [14] [6] [AuditEvent=CMC_RESPONSE_SENT][SubjectID=$Unidentified$][Outcome=Success][CMCResponse=MIIGPwYJKoZIhvcNAQcCoIIGMDCCBiwCAQMxDzANBglghkgBZQMEAgMFADA0BggrBgEFBQcMA6AoBCYwJDAeMBwCAQEGCCsGAQUFBwcZMQ0wCwIBAjADAgEBAgEHMAAwAKCCA+gwggPkMIICzKADAgECAgQM3QwgMA0GCSqGSIb3DQEBDQUAMFMxEjAQBgNVBAoMCVNFQ3VyZS1EczEcMBoGA1UECwwTZ2thcG9vcl9SSENTXzc1X3NzbDEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZTAeFw0xODAyMTExOTE4MjlaFw0zODAyMTExOTE4MjlaMFMxEjAQBgNVBAoMCVNFQ3VyZS1EczEcMBoGA1UECwwTZ2thcG9vcl9SSENTXzc1X3NzbDEfMB0GA1UEAwwWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZTCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBAJRuy2MpwSogHtg84aBToFzWzZmkqCdIlO363KqhGb9SDI7nYdJWfSuMW3sMpdxeP/E9DqaEgiTw1b3OBTxSojLHbcjzAiT4iRNv2kwZwMit7JmfemVWMHCwoGm80qrUwUoIcau/I86HXrGN6BjTzjHQJHMbefH+I2zqh0bXhcLCvfH/Vg4X39eQ1Fp/xtX2E8SvjgBagvFVMcUw9XCPk4Gn7i6TTY4fgqq7qqZqrsVNziA2NL07BqvX9joCI3RzJwnxzVP1r8fBA9sPLHrkYUxue/ObQo2uRL91OYdI3R4HLJilbrgYWrixziDXPr6UrbEsiEE+rSg4ff+0yBoGT78CAwEAAaOBvzCBvDAfBgNVHSMEGDAWgBRexDUJbLEkPOUGRug4ZhxMlYyjRjAPBgNVHRMBAf8EBTADAQH/MA4GA1UdDwEB/wQEAwIBxjAdBgNVHQ4EFgQUXsQ1CWyxJDzlBkboOGYcTJWMo0YwWQYIKwYBBQUHAQEETTBLMEkGCCsGAQUFBzABhj1odHRwOi8vY3NxYTQtZ3Vlc3QwNC5pZG0ubGFiLmVuZy5yZHUucmVkaGF0LmNvbToyNTA4MC9jYS9vY3NwMA0GCSqGSIb3DQEBDQUAA4IBAQBV+JNL9Gpm88yTiWPdJgHpiXVQusKJIchrRBTFA1ZbBTFJTcsjv5XrdvEGS4X5PcO6xzWxFLKiiS7T6LA0g6ghVubwqcHo3tmj+xHxNhVopwa9TxvXEPNwfnBFluUwRMoDy1ULb4/ohplmeGVkEeNLfTyo0xtpBSMj92iy6ZwYw5dmE0ZFxfx6hzUnk65qn8H2mIdnWHiRjkwQGCdrq2oizcVM0OaX5rz0msgqSWFO85XjX/IxPVJJNNixSgSFIirVLToModCqX2puWn4wermn8INI3k8MMPOxpEK6L6IFEfGUqXEr/YnRgAGrPljw39p2wU/SCnp8P8CVzIssi/x0MYIB8jCCAe4CAQEwWzBTMRIwEAYDVQQKDAlTRUN1cmUtRHMxHDAaBgNVBAsME2drYXBvb3JfUkhDU183NV9zc2wxHzAdBgNVBAMMFkNBIFNpZ25pbmcgQ2VydGlmaWNhdGUCBAzdDCAwDQYJYIZIAWUDBAIDBQCgajAXBgkqhkiG9w0BCQMxCgYIKwYBBQUHDAMwTwYJKoZIhvcNAQkEMUIEQEvv2Hre+zYecA1BQPgG1/2oiSly9W6NdK7+dN9RxLwLiAyPnTYH/6v+5z4bW4rdVvzS+N6RWR5fhCwr7OIr37EwDQYJKoZIhvcNAQENBQAEggEAK+9OkkkDSE+652cRCEQYBNwO6iLXbOGoVWas5ahTqvMLlSAYOTD8PVOrJvkTKcCyUQXMQc3SbGTurVFPL7o8PFwJ05jou0DmG3o4J6/Djbf+Gt0QVPW/tVwN4x49JrRB3LJXRv/EQU8EGn85/hYgcrLJMwUJzMnu5aeoilbotAItwzj6sFezHFCqTwu9aHWFYGlU07IAZJL/6LGX5q8V0iuU9eK92K2PuK3pH0Ya5KIWIWKg0igSgBZt6e4PkznU2ln7Am5hTrfM23EsvHOU7cBwIJHLVSotzj1fwkPO7rf7cOY1CCFjprjsJqj3qlhQN7WTpsPX1nPZkrmgVodYtg==] CMC response sent
0.http-bio-25443-exec-1 - [23/Feb/2018:00:19:55 EST] [14] [6] [AuditEvent=ACCESS_SESSION_TERMINATED][ClientIP=10.12.28.208][ServerIP=10.12.28.208][SubjectID=CN=Certecc,UID=Testing][Outcome=Success][Info=CLOSE_NOTIFY] access session terminated

Step 2: I try to verify event "CMC_PROOF_OF_IDENTIFICATION" in debug and audit logs.If you check the logs i saw that event CMC_PROOF_OF_IDENTIFICATION last time on 12 Feb. After that i re-run this test many times but it never occur.

[root@csqa4-guest04 ca]# grep "CMC_PROOF_OF_IDENTIFICATION" debug
[11/Feb/2018:14:51:46][http-bio-25080-exec-4]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:14:51:46][http-bio-25080-exec-4]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:14:53:58][http-bio-25080-exec-1]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:14:53:58][http-bio-25080-exec-1]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:14:55:27][http-bio-25080-exec-2]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:14:55:27][http-bio-25080-exec-2]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:14:58:39][http-bio-25080-exec-1]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:14:58:39][http-bio-25080-exec-1]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:15:02:03][http-bio-25080-exec-1]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:15:02:03][http-bio-25080-exec-1]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:15:03:00][http-bio-25080-exec-2]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[11/Feb/2018:15:03:00][http-bio-25080-exec-2]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:01:57:43][http-bio-25080-exec-7]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:01:57:43][http-bio-25080-exec-7]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:02:20:15][http-bio-25080-exec-8]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:02:20:15][http-bio-25080-exec-8]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:02:27:45][http-bio-25080-exec-9]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:02:27:45][http-bio-25080-exec-9]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:02:44:34][http-bio-25080-exec-1]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:02:44:34][http-bio-25080-exec-1]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:03:06:20][http-bio-25080-exec-2]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:03:06:20][http-bio-25080-exec-2]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:04:46:39][http-bio-25080-exec-3]: SignedAuditLogger: event CMC_PROOF_OF_IDENTIFICATION
[12/Feb/2018:04:46:39][http-bio-25080-exec-3]: LogFile: event type not selected: CMC_PROOF_OF_IDENTIFICATION

[root@csqa4-guest04 ca]# grep "CMC_PROOF_OF_IDENTIFICATION" signedAudit/*
[root@csqa4-guest04 ca]#

 Step 3: I check the CS.cfg to check for the event.
CS.cfg:
log.instance.SignedAudit.events=ACCESS_SESSION_ESTABLISH,ACCESS_SESSION_TERMINATED,AUTH,AUTHZ,CERT_REQUEST_PROCESSED,CERT_SIGNING_INFO,CMC_SIGNED_REQUEST_SIG_VERIFY,CMC_USER_SIGNED_REQUEST_SIG_VERIFY,CMC_REQUEST_RECEIVED,CMC_RESPONSE_SENT,CONFIG_AUTH,CONFIG_CERT_PROFILE,CONFIG_ENCRYPTION,CONFIG_ROLE,CONFIG_SERIAL_NUMBER,CONFIG_SIGNED_AUDIT,CONFIG_TRUSTED_PUBLIC_KEY,CRL_SIGNING_INFO,DELTA_CRL_GENERATION,FULL_CRL_GENERATION,LOG_PATH_CHANGE,OCSP_GENERATION,OCSP_SIGNING_INFO,PROFILE_CERT_REQUEST,PROOF_OF_POSSESSION,RANDOM_GENERATION,ROLE_ASSUME,SECURITY_DOMAIN_UPDATE,SELFTESTS_EXECUTION

[root@csqa4-guest04 ca]# grep -i "CMC_PROOF_OF_IDENTIFICATION" /etc/pki/gkapoor_RHCS_75_ssl/ca/CS.cfg
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,CERT_SIGNING_INFO,OCSP_SIGNING_INFO,CRL_SIGNING_INFO,NON_PROFILE_CERT_REQUEST,PROFILE_CERT_REQUEST,CERT_REQUEST_PROCESSED,CERT_STATUS_CHANGE_REQUEST,CERT_STATUS_CHANGE_REQUEST_PROCESSED,AUTHZ,INTER_BOUNDARY,AUTH,CERT_PROFILE_APPROVAL,PROOF_OF_POSSESSION,CMC_PROOF_OF_IDENTIFICATION,CMC_ID_POP_LINK_WITNESS,SCHEDULE_CRL_GENERATION,DELTA_CRL_GENERATION,DELTA_CRL_PUBLISHING,FULL_CRL_GENERATION,FULL_CRL_PUBLISHING,CRL_RETRIEVAL,CRL_VALIDATION,CMC_SIGNED_REQUEST_SIG_VERIFY,CMC_USER_SIGNED_REQUEST_SIG_VERIFY,CMC_REQUEST_RECEIVED,CMC_RESPONSE_SENT,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_GENERATION,COMPUTE_RANDOM_DATA_REQUEST,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_SUCCESS,COMPUTE_RANDOM_DATA_REQUEST_PROCESSED_FAILURE,CIMC_CERT_VERIFICATION,SECURITY_DOMAIN_UPDATE,CONFIG_SERIAL_NUMBER,AUTHORITY_CONFIG,ACCESS_SESSION_ESTABLISH,ACCESS_SESSION_TERMINATED,SECURITY_DATA_ARCHIVAL_REQUEST,RANDOM_GENERATION
Comment 11 Christina Fu 2018-02-23 17:21:53 UTC 
ok it looks like we didn't enable AuditEvent=CMC_PROOF_OF_IDENTIFICATION by default.  As it would then supposed to record the attempted subject.
Could you enable it and see if it indeed does that?

Maybe I can enable it at the next CMC bug that I work on.

But as far as this bug goes, I think it looks good.
Comment 12 Geetika Kapoor 2018-02-23 18:20:15 UTC 
I think we can move this bug to verified. 
I can add Above mentioned details in https://bugzilla.redhat.com/show_bug.cgi?id=1540440.

I have added "CMC_PROOF_OF_IDENTIFICATION" in log.instance.SignedAudit.events in CS.cfg and restart the instance.

log.instance.SignedAudit.events=ACCESS_SESSION_ESTABLISH,ACCESS_SESSION_TERMINATED,AUTH,AUTHZ,CERT_REQUEST_PROCESSED,CERT_SIGNING_INFO,CMC_SIGNED_REQUEST_SIG_VERIFY,CMC_USER_SIGNED_REQUEST_SIG_VERIFY,CMC_REQUEST_RECEIVED,CMC_RESPONSE_SENT,CONFIG_AUTH,CONFIG_CERT_PROFILE,CONFIG_ENCRYPTION,CONFIG_ROLE,CONFIG_SERIAL_NUMBER,CONFIG_SIGNED_AUDIT,CONFIG_TRUSTED_PUBLIC_KEY,CRL_SIGNING_INFO,DELTA_CRL_GENERATION,FULL_CRL_GENERATION,LOG_PATH_CHANGE,OCSP_GENERATION,OCSP_SIGNING_INFO,PROFILE_CERT_REQUEST,PROOF_OF_POSSESSION,RANDOM_GENERATION,ROLE_ASSUME,SECURITY_DOMAIN_UPDATE,SELFTESTS_EXECUTION,CMC_PROOF_OF_IDENTIFICATION


I couldn't find "CMC_PROOF_OF_IDENTIFICATION" in audit or debug logs.
Comment 13 Geetika Kapoor 2018-02-23 20:16:46 UTC 
Marking This bug "Verified" and adding all the observed behavior and issues in https://bugzilla.redhat.com/show_bug.cgi?id=1540440.
Comment 15 errata-xmlrpc 2018-04-10 17:02:54 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/RHBA-2018:0925
Note You need to log in before you can comment on or make changes to this bug.