freeipa

Clone
Source Code
GIT

#6899 ipa vault: archival and retrival is broken in IPA 4.5.0
Closed: fixed 7 years ago Opened 7 years ago by cheimes.

Closed: fixed
Reopen Issue

ipa vault-retrieve is not able to retrieve previously archived vault data any more:

user vault

$ ipa vault-add --type=standard usertest
----------------------
Added vault "usertest"
----------------------
  Vault name: usertest
  Type: standard
  Owner users: admin
  Vault user: admin
$ ipa vault-archive usertest --data="ZGF0YQo="
-----------------------------------
Archived data into vault "usertest"
-----------------------------------
$ ipa vault-retrieve usertest
ipa: ERROR: No archived data.

service vault

$ ipa host-add client1.ipa.example --force
$ ipa service-add custodia/client1.ipa.example --force
$ ipa vault-add --type=standard --service=custodia/client1.ipa.example test
------------------
Added vault "test"
------------------
  Vault name: test
  Type: standard
  Owner users: admin
  Vault service: custodia/client1.ipa.example@DOM-058-099.IPA.EXAMPLE
$ ipa vault-archive --service=custodia/client1.ipa.example test --data="ZGF0YQo="
-------------------------------
Archived data into vault "test"
-------------------------------
$ ipa vault-retrieve --service=custodia/client1.ipa.example test
ipa: ERROR: No archived data.

version

$ rpm -qa ipa-server pki-kra
pki-kra-10.4.1-2.el7.noarch
ipa-server-4.5.0-8.el7.x86_64

httpd error log

[Wed Apr 26 11:26:59.146430 2017] [auth_gssapi:error] [pid 32679] [client 2620:52:0:224e:21a:4aff:fe23:15c4:59726] NO AUTH DATA Client did not send any authentication headers, referer: https://vm-058-099.ipa.example/ipa/xml
[Wed Apr 26 11:26:59.242203 2017] [:error] [pid 32534] ipa: INFO: [jsonserver_session] admin@DOM-058-099.IPA.EXAMPLE: vault_show/1(u'usertest', version=u'2.224'): SUCCESS
[Wed Apr 26 11:26:59.276368 2017] [auth_gssapi:error] [pid 32679] [client 2620:52:0:224e:21a:4aff:fe23:15c4:59726] NO AUTH DATA Client did not send any authentication headers, referer: https://vm-058-099.ipa.example/ipa/xml
[Wed Apr 26 11:26:59.477688 2017] [:error] [pid 32533] ipa: INFO: [jsonserver_session] admin@DOM-058-099.IPA.EXAMPLE: vault_archive_internal/1(u'usertest', session_key='=_\\xf9\\xf5\\x87\\x1cd\\x87aT\\xd9\\xa8\\\\\\xfe\\x9e\\xa1P\\xc3\\xdb\\xeb\\xc1\\xbf\\xa2\\x06\\xbc\\x19\\xba\\xf9\\xf8\\xb4\\xfe\\xeacT[\\xf7(V\\x91\\x11\\xf7\\x94\\xd1\\xb5\\xa9G\\x9cJM\\x0e\\x15\\xcfj\\x8f]u\\xea:\\x83\\xb6\\x07\\xf6\\x8e\\x06\\xa4 9\\x87\\xfb\\xcf\\x95\\xb9\\xf9\\xd5&c\\x9bv&\\xcc\\x15_\\xa3\\xd1\\xe3\\xae\\xb9\\xc1\\xcb\\x83\\xe4\\xc9y\\x83\\x89&~\\xc3\\x0e*\\x1e\\xf6<\\xdey>\\xc9G\\xa4\\xcb\\xad\\xb9\\x15\\x93%\\x06S\\xbc\\x93\\xb6_\\x08\\x1f\\x95\\x82\\xca\\xb5X\\xf61\\xb0\\xe4\\xad \\xa4or(9\\xdb\\xc0\\xbb^\\xc5\\x04\\t9\\xfc#02\\xbd\\na\\x04&\\x007W\\x8e\\x04#\\xae\\x86\\xb7,$^Q\\xeb,\\xbe\\xcf\\xab\\xbd\\xf3\\xb9C\\xf2\\xbe\\x834IPf\\xf3\\xc8\\x9cg\\n_\\xda\\xdf\\xe6\\x113\\xce\\t\\xcc\\x85\\xec\\xe8\\x87\\xa2\\xc2\\xddk\\xe4]\\xd5\\x80\\xcc\\x03\\x02\\x16\\x07\\x06\\xc6\\x15av\\x81\\xa1\\xee\\xc6\\x03m#\\xadE\\xbei\\x16sJXd\\x854\\xa6\\x84\\xb7\\xe2\\xbb\\xcb`0\\xa3\\x0e \\xbb\\xedjcP#', vault_data='\\x05z\\xf8\\x03\\xc8\\x05\\xcd\\xf3H\\xeb{\\xa8kN\\xc7\\xaf\\xb5\\xc7\\x9d\\xbd(\\xa3t\\xcb', nonce='X\\xb1S\\xdc[Q\\xe0`', version=u'2.224'): SUCCESS
[Wed Apr 26 11:27:06.164022 2017] [:warn] [pid 33246] [client 2620:52:0:224e:21a:4aff:fe23:15c4:59738] failed to set perms (3140) on file (/var/run/ipa/ccaches/admin@DOM-058-099.IPA.EXAMPLE)!, referer: https://vm-058-099.ipa.example/ipa/xml
[Wed Apr 26 11:27:06.207384 2017] [:error] [pid 32534] ipa: INFO: [jsonserver_session] admin@DOM-058-099.IPA.EXAMPLE: vault_show/1(u'usertest', version=u'2.224'): SUCCESS
[Wed Apr 26 11:27:06.239085 2017] [:warn] [pid 33246] [client 2620:52:0:224e:21a:4aff:fe23:15c4:59738] failed to set perms (3140) on file (/var/run/ipa/ccaches/admin@DOM-058-099.IPA.EXAMPLE)!, referer: https://vm-058-099.ipa.example/ipa/xml
[Wed Apr 26 11:27:06.410686 2017] [:error] [pid 32533] ipa: INFO: [jsonserver_session] admin@DOM-058-099.IPA.EXAMPLE: vault_retrieve_internal/1(u'usertest', session_key="Or%\\xd0\\xc9@\\x97n\\xbbF\\x059\\xe9D,\\xa4\\x93\\xb4\\xcar\\x14\\xf5r\\x0b\\xf6\\xb6\\xc6\\xd3\\x01\\x8cq\\xc7\\x84\\x90\\xbb\\xd2(\\x88+\\xb9\\x8e9^\\xb5\\xb4\\xc9\\xa0\\x9e\\xde\\xbc\\xf2\\xd9\\x8fd-R\\x19\\xbc\\x94`\\xd2\\x03\\xee!;\\xe1K\\xc7b\\xef\\xa7m\\x99\\xb1:&\\x7f\\xda\\x9d*\\x85\\x92\\xf7\\x98\\xd0\\xae\\xb4\\xcc\\xee\\xdd\\xf5\\xe3\\x0c/\\x95\\xab\\xeb\\xd0\\xb8\\x1c#\\xfb\\xbd%\\x84\\x04 \\x1e\\x8f9\\xfa\\x8f\\xc8\\x1a\\x0e/\\xecv\\x0e\\xa1\\xc1\\xd3A<\\xf5\\xf7\\xb8\\xe0}\\x84\\xd8\\xa8\\xd2\\xc4.s\\xd67\\xe5\\x87)l}g<\\xff\\xf1\\xccq\\xda\\x7f*\\x18\\x1d\\x1d\\xe5\\x05\\xfc\\xef\\xbe\\xd4aR\\x0cC\\xea\\x1cC\\x0f\\x10Or\\x13\\x08\\xb3\\xfalOL\\x13\\x07(\\xf9\\xe1\\x0fz\\x04\\xb7\\xb6\\xfb('e`\\xdbd\\x93\\xaa_V\\x819\\xad\\xf9\\xe0\\x13\\x8d\\xb1;\\x02\\x05\\x1f\\x0f\\xd8\\xb0F\\xd9\\xdd\\xc2\\xd9N1\\xf9\\x12\\xb0\\xe4`t\\xaa\\x8f\\xbbg\\x99\\x13\\xfa}i\\x81Tmo\\xe2(DX_\\xf77\\x9a\\xee\\xb6\\xbc\\xd9P5d", version=u'2.224'): NotFound

Abhijeet discovered the bug yesterday, https://bugzilla.redhat.com/show_bug.cgi?id=1445382

Further investigation shows that ou=keyRepository,ou=kra,o=kra,o=ipaca is empty. The subtree is should contain all archived data.

Here is the KRA debug log for a vault-add event. KRAService serviceRequest EBaseException:Can't decrypt passphrase. sounds fishy.

[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: SessionContextInterceptor: KeyRequestResource.submitRequest()
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: SessionContextInterceptor: principal: ipakra
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: AuthMethodInterceptor: KeyRequestResource.submitRequest()
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: AuthMethodInterceptor: mapping: keyrequests
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: AuthMethodInterceptor: required auth methods: [certUserDBAuthMgr]
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: AuthMethodInterceptor: authentication manager: certUserDBAuthMgr
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: AuthMethodInterceptor: access granted
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: ACLInterceptor: KeyRequestResource.submitRequest()
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: ACLInterceptor: principal: ipakra
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: ACLInterceptor: will use authz manager DirAclAuthz
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: ACLInterceptor: mapping: keyrequests
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: ACLInterceptor: ACL: certServer.kra.keyrequests,execute
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: checkACLS(): ACLEntry expressions= group="Data Recovery Manager Agents"
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: evaluating expressions: group="Data Recovery Manager Agents"
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: GroupAccessEvaluator: evaluate: uid=ipakra value="Data Recovery Manager Agents"
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: GroupAccessEvaluator: evaluate: no groups in authToken
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: In LdapBoundConnFactory::getConn()
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: masterConn is connected: true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: conn is connected true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: mNumConns now 2
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: returnConn: mNumConns now 3
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: UGSubsystem.isMemberOf() using new lookup code
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: In LdapBoundConnFactory::getConn()
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: masterConn is connected: true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: conn is connected true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: mNumConns now 2
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: authorization search base: cn=Data Recovery Manager Agents,ou=groups,o=kra,o=ipaca
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: authorization search filter: (uniquemember=uid=ipakra,ou=people,o=kra,o=ipaca)
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: authorization result: true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: returnConn: mNumConns now 3
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: evaluated expression: group="Data Recovery Manager Agents" to be true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: DirAclAuthz: authorization passed
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: ACLInterceptor: access granted
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: SignedAuditEventFactory: create() message created for eventType=AUTHZ_SUCCESS

[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: MessageFormatInterceptor: KeyRequestResource.submitRequest()
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: MessageFormatInterceptor: content-type: application/json
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: MessageFormatInterceptor: accept: [application/json]
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: MessageFormatInterceptor: request format: application/json
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: MessageFormatInterceptor: response format: application/json
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: In LdapBoundConnFactory::getConn()
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: masterConn is connected: true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: conn is connected true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: mNumConns now 2
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: returnConn: mNumConns now 3
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: Repository: in getNextSerialNumber.
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: Repository: checkRange  mLastSerialNo=20
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: Repository: getNextSerialNumber: returning retSerial 20
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: GenericPolicyProcessor: apply begins
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: GenericPolicyProcessor: apply not ProfileRequest. op=securityDataEnrollment
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: GenericPolicyProcessor: apply begins
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: GenericPolicyProcessor: apply not ProfileRequest. op=securityDataEnrollment
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: SecurityDataProcessor.archive. Request id: 20
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: SecurityDataProcessor.archive wrappedSecurityData: RWeZu3sXjtNvwaFVShlXJQ==
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: EncryptionUnit.decryptExternalPrivate
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: KRAService serviceRequest EBaseException:Can't decrypt passphrase.
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: In LdapBoundConnFactory::getConn()
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: masterConn is connected: true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: conn is connected true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: mNumConns now 2
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: returnConn: mNumConns now 3
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: In LdapBoundConnFactory::getConn()
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: masterConn is connected: true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: conn is connected true
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: getConn: mNumConns now 2
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: returnConn: mNumConns now 3
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: ARequestNotifier  notify mIsPublishingQueueEnabled=false mMaxThreads=1
[26/Apr/2017:15:39:53][Thread-49]: RunListeners:: noQueue  SingleRequest
[26/Apr/2017:15:39:53][Thread-49]: RunListeners:  noQueue  SingleRequest
[26/Apr/2017:15:39:53][ajp-bio-127.0.0.1-8009-exec-4]: SignedAuditEventFactory: create() message created for eventType=SECURITY_DATA_ARCHIVAL_REQUEST

A successful store operation on a different machine looks like this:

[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: GenericPolicyProcessor: apply begins
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: GenericPolicyProcessor: apply not ProfileRequest. op=securityDataEnrollment
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: GenericPolicyProcessor: apply begins
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: GenericPolicyProcessor: apply not ProfileRequest. op=securityDataEnrollment
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: SecurityDataService.serviceRequest. Request id: 22
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: SecurityDataService.serviceRequest wrappedSecurityData: ePWq0QUkaslgbetIkDlDnQ==
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: EncryptionUnit.decryptExternalPrivate
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: EncryptionUnit.encryptInternalPrivate
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: Repository: in getNextSerialNumber. 
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: Repository: checkRange  mLastSerialNo=17
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: Repository: getNextSerialNumber: returning retSerial 17
[12/Apr/2017:11:10:57][ajp-nio-127.0.0.1-8009-exec-3]: KRA adding Security Data key record 17

Problem might be caused by Dogtag 10.4. My working system has pki-kra-10.3.5-11.fc25 on Fedora 25, the broken system pki-kra-10.4.1-2.el7.

Looks like this might have been caused by changes in the Dogtag key client for AES. Basically, it looks like we're adding the OID for AES encryption in a case where we should likely be adding the one for 3DES. Trying out a fix.

Metadata Update from @pvoborni:
- Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1445382
7 years ago

Metadata Update from @pvoborni:
- Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1445382
7 years ago

Issue linked to bug 1445382

I have verified the patch successfully with Dogtag 10.4 and FreeIPA 4.5.0.

master:

  • 5197422 Vault: Explicitly default to 3DES CBC

ipa-4-5:

  • e94a1d1 Vault: Explicitly default to 3DES CBC

Metadata Update from @mbasti:
- Issue close_status updated to: fixed
- Issue status updated to: Closed (was: Open)
7 years ago

Metadata Update from @mbasti:
- Issue set to the milestone: FreeIPA 4.5.1
- Issue status updated to: Open (was: Closed)
7 years ago

Metadata Update from @mbasti:
- Issue close_status updated to: fixed
- Issue status updated to: Closed (was: Open)
7 years ago

Log in to comment on this ticket.

Metadata
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
None
Powered by Pagure 5.14.1
Documentation • File an Issue • About • SSH Hostkey/Fingerprint
© Red Hat, Inc. and others.