#2710 Key recovery on token fails because key record is not marked encrypted
Closed: fixed 6 years ago Opened 6 years ago by mharmsen.

Key recovery on token fails because key record is not marked encrypted

Steps to Reproduce:

1. Install CA, KRA, TKS and TPS on an HSM and FIPS enabled server with
    server-side keygen enabled on TPS
2. Enroll a token using TPS
3. Mark the token physically damaged
4. Issue a new token for the user

Actual results:

Key recovery during new token enrollment fails.

Expected results:

Issuing a new token should be successful and cert/key on the damaged token
should be recovered onto the new token

Additional info:

KRA debug log

[25/May/2017:09:34:54][http-bio-31042-exec-13]: SignedAuditEventFactory:
create() message created for eventType=ACCESS_SESSION_ESTABLISH_SUCCESS
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet:service() uri =
/kra/agent/kra/TokenKeyRecovery
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet::service() param
name='tokencuid' value='40906145C76224192809'
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet::service() param
name='userid' value='scuser1'
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet::service() param
name='cert'
value='MIIC/jCCAeagAwIBAgIEC100DTANBgkqhkiG9w0BAQ0FADBaMSAwHgYDVQQKDBdw
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet::service() param
name='drm_trans_desKey' value='(sensitive)'
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet: kraTokenKeyRecovery
start to service.
[25/May/2017:09:34:54][http-bio-31042-exec-13]: IP: 10.8.60.15
[25/May/2017:09:34:54][http-bio-31042-exec-13]: AuthMgrName: certUserDBAuthMgr
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet: retrieving SSL
certificate
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet:
certUID=CN=Subsystem Certificate,OU=pki-tps-May23,O=idm.lab.eng.rdu2.redhat.com
Security Domain
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CertUserDBAuth: started
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CertUserDBAuth: Retrieving
client certificate
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CertUserDBAuth: Got client
certificate
[25/May/2017:09:34:54][http-bio-31042-exec-13]: Authentication: client
certificate found
[25/May/2017:09:34:54][http-bio-31042-exec-13]: In
LdapBoundConnFactory::getConn()
[25/May/2017:09:34:54][http-bio-31042-exec-13]: masterConn is connected: true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: conn is connected true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: mNumConns now 2
[25/May/2017:09:34:54][http-bio-31042-exec-13]: returnConn: mNumConns now 3
[25/May/2017:09:34:54][http-bio-31042-exec-13]: Authentication: mapped
certificate to user
[25/May/2017:09:34:54][http-bio-31042-exec-13]: authenticated
uid=TPS-nocp1.idm.lab.eng.rdu2.redhat.com-25443,ou=people,o=pki-kra-May23-KRA
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet:
userid=TPS-nocp1.idm.lab.eng.rdu2.redhat.com-25443
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet: in auditSubjectID
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet: auditSubjectID
auditContext {locale=en_US, userid=TPS-nocp1.idm.lab.eng.rdu2.redhat.com-25443,
ipAddress=10.8.60.15, authManagerId=certUserDBAuthMgr}
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet auditSubjectID:
subjectID: TPS-nocp1.idm.lab.eng.rdu2.redhat.com-25443
[25/May/2017:09:34:54][http-bio-31042-exec-13]: SignedAuditEventFactory:
create() message created for eventType=AUTH_SUCCESS
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet: in auditSubjectID
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet: auditSubjectID
auditContext {locale=en_US, userid=TPS-nocp1.idm.lab.eng.rdu2.redhat.com-25443,
ipAddress=10.8.60.15, authManagerId=certUserDBAuthMgr}
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet auditSubjectID:
subjectID: TPS-nocp1.idm.lab.eng.rdu2.redhat.com-25443
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet: in auditGroupID
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet: auditGroupID
auditContext {locale=en_US, userid=TPS-nocp1.idm.lab.eng.rdu2.redhat.com-25443,
ipAddress=10.8.60.15, authManagerId=certUserDBAuthMgr}
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet auditGroupID:
groupID: null
[25/May/2017:09:34:54][http-bio-31042-exec-13]: checkACLS(): ACLEntry
expressions= group="Data Recovery Manager Agents"
[25/May/2017:09:34:54][http-bio-31042-exec-13]: evaluating expressions:
group="Data Recovery Manager Agents"
[25/May/2017:09:34:54][http-bio-31042-exec-13]: GroupAccessEvaluator: evaluate:
uid=TPS-nocp1.idm.lab.eng.rdu2.redhat.com-25443 value="Data Recovery Manager
Agents"
[25/May/2017:09:34:54][http-bio-31042-exec-13]: GroupAccessEvaluator: evaluate:
no groups in authToken
[25/May/2017:09:34:54][http-bio-31042-exec-13]: In
LdapBoundConnFactory::getConn()
[25/May/2017:09:34:54][http-bio-31042-exec-13]: masterConn is connected: true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: conn is connected true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: mNumConns now 2
[25/May/2017:09:34:54][http-bio-31042-exec-13]: returnConn: mNumConns now 3
[25/May/2017:09:34:54][http-bio-31042-exec-13]: UGSubsystem.isMemberOf() using
new lookup code
[25/May/2017:09:34:54][http-bio-31042-exec-13]: In
LdapBoundConnFactory::getConn()
[25/May/2017:09:34:54][http-bio-31042-exec-13]: masterConn is connected: true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: conn is connected true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: mNumConns now 2
[25/May/2017:09:34:54][http-bio-31042-exec-13]: authorization search base:
cn=Data Recovery Manager Agents,ou=groups,o=pki-kra-May23-KRA
[25/May/2017:09:34:54][http-bio-31042-exec-13]: authorization search filter: (u
niquemember=uid=TPS-nocp1.idm.lab.eng.rdu2.redhat.com-25443,ou=people,o=pki-kra
-May23-KRA)
[25/May/2017:09:34:54][http-bio-31042-exec-13]: authorization result: true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: returnConn: mNumConns now 3
[25/May/2017:09:34:54][http-bio-31042-exec-13]: evaluated expression:
group="Data Recovery Manager Agents" to be true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: DirAclAuthz: authorization
passed
[25/May/2017:09:34:54][http-bio-31042-exec-13]: SignedAuditEventFactory:
create() message created for eventType=AUTHZ_SUCCESS
[25/May/2017:09:34:54][http-bio-31042-exec-13]: In
LdapBoundConnFactory::getConn()
[25/May/2017:09:34:54][http-bio-31042-exec-13]: masterConn is connected: true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: conn is connected true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: mNumConns now 2
[25/May/2017:09:34:54][http-bio-31042-exec-13]: returnConn: mNumConns now 3
[25/May/2017:09:34:54][http-bio-31042-exec-13]: SignedAuditEventFactory:
create() message created for eventType=ROLE_ASSUME
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryServlet:
processTokenKeyRecovery would be called
[25/May/2017:09:34:54][http-bio-31042-exec-13]: processTokenKeyRecovery begins:
[25/May/2017:09:34:54][http-bio-31042-exec-13]: Repository: in
getNextSerialNumber.
[25/May/2017:09:34:54][http-bio-31042-exec-13]: Repository: checkRange
mLastSerialNo=13
[25/May/2017:09:34:54][http-bio-31042-exec-13]: Repository:
getNextSerialNumber: returning retSerial 13
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryServlet:
processTokenKeyRecovery(): received request parameter: cert
[25/May/2017:09:34:54][http-bio-31042-exec-13]: GenericPolicyProcessor: apply
begins
[25/May/2017:09:34:54][http-bio-31042-exec-13]: GenericPolicyProcessor: apply
not ProfileRequest. op=netkeyKeyRecovery
[25/May/2017:09:34:54][http-bio-31042-exec-13]: GenericPolicyProcessor: apply
begins
[25/May/2017:09:34:54][http-bio-31042-exec-13]: GenericPolicyProcessor: apply
not ProfileRequest. op=netkeyKeyRecovery
[25/May/2017:09:34:54][http-bio-31042-exec-13]: KRA services token key recovery
request
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getVolatileRequest params null
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService:
received DRM-trans-wrapped des key
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService:
wrapped_des_key specialDecoded
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService:
received des key
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService: got
token slot:NHSM-RPATTATH-SOFTCARD
[25/May/2017:09:34:54][http-bio-31042-exec-13]: KRA reading key record
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService:
recover by cert
[25/May/2017:09:34:54][http-bio-31042-exec-13]: In
LdapBoundConnFactory::getConn()
[25/May/2017:09:34:54][http-bio-31042-exec-13]: masterConn is connected: true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: conn is connected true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: mNumConns now 2
[25/May/2017:09:34:54][http-bio-31042-exec-13]: filter= (publicKey=x509cert#"MI
IC/jCCAeagAwIBAgIEC100DTANBgkqhkiG9w0BAQ0FADBaMSAwHgYDVQQKDBdw
[25/May/2017:09:34:54][http-bio-31042-exec-13]: returnConn: mNumConns now 3
[25/May/2017:09:34:54][http-bio-31042-exec-13]: read key record
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService: owner
name on record =40906145C76224192809:scuser1
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService: owner
name from TPS =40906145C76224192809:scuser1
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService: owner
name matches
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService:
recoverKey() - with allowEncDecrypt_archival being false
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService:
recoverKey() - allowEncDecrypt_archival needs to be false for this call
[25/May/2017:09:34:54][http-bio-31042-exec-13]: TokenKeyRecoveryService:
Recovery Failed recoverKey, allowEncDecrypt_archival needs to be false for this
call
[25/May/2017:09:34:54][http-bio-31042-exec-13]: ARequestNotifier  notify
mIsPublishingQueueEnabled=false mMaxThreads=1
[25/May/2017:09:34:54][http-bio-31042-exec-13]: processTokenKeyRecovery
finished
[25/May/2017:09:34:54][http-bio-31042-exec-13]: In
LdapBoundConnFactory::getConn()
[25/May/2017:09:34:54][http-bio-31042-exec-13]: masterConn is connected: true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: conn is connected true
[25/May/2017:09:34:54][http-bio-31042-exec-13]: getConn: mNumConns now 2
[25/May/2017:09:34:54][Thread-18]: RunListeners:: noQueue  SingleRequest
[25/May/2017:09:34:54][Thread-18]: RunListeners:  noQueue  SingleRequest
[25/May/2017:09:34:54][http-bio-31042-exec-13]: returnConn: mNumConns now 3
[25/May/2017:09:34:54][http-bio-31042-exec-13]:
TokenKeyRecoveryServlet:outputString.length 8
[25/May/2017:09:34:54][http-bio-31042-exec-13]: CMSServlet: curDate=Thu May 25
09:34:54 EDT 2017 id=kraTokenKeyRecovery time=83
[25/May/2017:09:34:54][http-bio-31042-exec-13]: SignedAuditEventFactory:
create() message created for eventType=ACCESS_SESSION_TERMINATED

Metadata Update from @mharmsen:
- Custom field component adjusted to General
- Custom field feature adjusted to ''
- Custom field origin adjusted to Community
- Custom field proposedmilestone adjusted to ''
- Custom field proposedpriority adjusted to ''
- Custom field reviewer adjusted to ''
- Custom field type adjusted to defect
- Custom field version adjusted to ''
- Issue assigned to vakwetu
- Issue priority set to: blocker
- Issue set to the milestone: 10.4

6 years ago

Metadata Update from @mharmsen:
- Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1455617

6 years ago

Fxied here:

commit 5438e24e022c4c169ff9b5c6325e5ec0023d4caa
Author: Ade Lee alee@redhat.com
Date: Thu May 25 16:31:45 2017 -0400

Set encryption flag for generated keys

The key record for keys generated in the keygen servlets
was not updated to reflect whether or not the server was set up
to do encryption/key wrapping.  This patch corrects this
oversight.

Bugzilla BZ# 1455617

Change-Id: I31daece8b93a0ad58cb595e6a23fe8705f338024

Metadata Update from @vakwetu:
- Issue close_status updated to: fixed
- Issue status updated to: Closed (was: Open)

6 years ago

Metadata Update from @mharmsen:
- Issue set to the milestone: 10.4.6 (was: 10.4)

6 years ago

Metadata Update from @mharmsen:
- Issue set to the milestone: 10.4 (was: 10.4.6)
- Issue status updated to: Open (was: Closed)

6 years ago

This bug status was incorrectly moved due to a testing misunderstanding.

Metadata Update from @mharmsen:
- Issue close_status updated to: fixed
- Issue set to the milestone: 10.4.6 (was: 10.4)
- Issue status updated to: Closed (was: Open)

6 years ago

Metadata Update from @mharmsen:
- Custom field fixedinversion adjusted to pki-core-10.4.7-1.fc27

6 years ago

Dogtag PKI is moving from Pagure issues to GitHub issues. This means that existing or new
issues will be reported and tracked through Dogtag PKI's GitHub Issue tracker.

This issue has been cloned to GitHub and is available here:
https://github.com/dogtagpki/pki/issues/2830

If you want to receive further updates on the issue, please navigate to the
GitHub issue and click on Subscribe button.

Thank you for understanding, and we apologize for any inconvenience.

Login to comment on this ticket.

Metadata