#7462 Error messages during CA and KRA removal
Closed: fixed by rcritten. Opened by cheimes.

Issue

On Fedora 28, ipa-server-install --uninstall prints several scary warnings during removal of Dogtag's CA and KRA instance.

Steps to Reproduce

  1. ipa-server-install
  2. ipa-server-install --uninstall

Actual behavior

Warnings and errors

Expected behavior

No warnings

Version/Release/Distribution

freeipa-server-4.6.90.pre1-6.1.fc28.x86_64
freeipa-client-4.6.90.pre1-6.1.fc28.x86_64
package ipa-server is not installed
package ipa-client is not installed
389-ds-base-1.4.0.6-2.fc28.x86_64
pki-ca-10.6.0-0.2.fc28.noarch
krb5-server-1.16-12.fc28.x86_64

Additional info:

From the uninstaller log:

2018-03-23T08:50:39Z DEBUG args=['/usr/sbin/pkidestroy', '-i', 'pki-tomcat', '-s', 'KRA']
2018-03-23T08:50:46Z DEBUG Process finished, return code=0
2018-03-23T08:50:46Z DEBUG stdout=Log file: /var/log/pki/pki-kra-destroy.20180323095041.log
Loading deployment configuration from /var/lib/pki/pki-tomcat/kra/registry/kra/deployment.cfg.
WARNING: The 'pki_ssl_server_nickname' in [KRA] has been deprecated. Use 'pki_sslserver_nickname' instead.
WARNING: The 'pki_ssl_server_subject_dn' in [KRA] has been deprecated. Use 'pki_sslserver_subject_dn' instead.
Uninstalling KRA from /var/lib/pki/pki-tomcat.
Uninstallation complete.
2018-03-23T08:50:46Z DEBUG stderr=pkidestroy  : ERROR    ....... unable to access security domain. Continuing .. HTTPSConnectionPool(host='master.ipa.example', port=443): Max retries exceeded with url: /ca/rest/securityDomain/domainInfo (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fcddf0f1ac8>: Failed to establish a new connection: [Errno 111] Connection refused',)) 
pkidestroy  : WARNING  ....... this 'KRA' entry will NOT be deleted from security domain 'IPA'!
pkidestroy  : WARNING  ....... security domain 'IPA' may be offline or unreachable!
pkidestroy  : ERROR    ....... subprocess.CalledProcessError:  Command '['/usr/bin/sslget', '-n', 'subsystemCert cert-pki-ca', '-p', '1Ho}IFfX9GL-t.T[vfAA8QiHGdi,Z?w-iyXGuW$]Y', '-d', '/etc/pki/pki-tomcat/alias', '-e', 'name="/var/lib/pki/pki-tomcat"&type=KRA&list=kraList&host=master.ipa.example&sport=443&ncsport=443&adminsport=443&agentsport=443&operation=remove', '-v', '-r', '/ca/agent/ca/updateDomainXML', 'master.ipa.example:443']' returned non-zero exit status 6.!
2018-03-23T08:50:49Z DEBUG args=['/usr/sbin/pkidestroy', '-i', 'pki-tomcat', '-s', 'CA']
2018-03-23T08:50:53Z DEBUG Process finished, return code=0
2018-03-23T08:50:53Z DEBUG stdout=Log file: /var/log/pki/pki-ca-destroy.20180323095051.log
Loading deployment configuration from /var/lib/pki/pki-tomcat/ca/registry/ca/deployment.cfg.
WARNING: The 'pki_ssl_server_nickname' in [CA] has been deprecated. Use 'pki_sslserver_nickname' instead.
WARNING: The 'pki_ssl_server_subject_dn' in [CA] has been deprecated. Use 'pki_sslserver_subject_dn' instead.
Uninstalling CA from /var/lib/pki/pki-tomcat.
Uninstallation complete.
2018-03-23T08:50:53Z DEBUG stderr=pkidestroy  : WARNING  ....... this 'CA' entry will NOT be deleted from security domain 'IPA'!
pkidestroy  : WARNING  ....... security domain 'IPA' may be offline or unreachable!
pkidestroy  : ERROR    ....... subprocess.CalledProcessError:  Command '['/usr/bin/sslget', '-n', 'subsystemCert cert-pki-ca', '-p', '1Ho}IFfX9GL-t.T[vfAA8QiHGdi,Z?w-iyXGuW$]Y', '-d', '/etc/pki/pki-tomcat/alias', '-e', 'name="/var/lib/pki/pki-tomcat"&type=CA&list=caList&host=master.ipa.example&sport=443&ncsport=443&adminsport=443&agentsport=443&operation=remove', '-v', '-r', '/ca/agent/ca/updateDomainXML', 'master.ipa.example:443']' returned non-zero exit status 6.!
pkidestroy  : WARNING  ....... Directory '/etc/pki/pki-tomcat/alias' is either missing or is NOT a directory!

I'm still getting error messages with freeipa-server-4.8.1-1.fc30.x86_64 and pki-ca-10.7.3-3.fc30.noarch:

# ipa-server-install --uninstall -U
...
Shutting down all IPA services
Unconfiguring KRA
failed to uninstall KRA instance CalledProcessError(Command ['/usr/sbin/pkidestroy', '-i', 'pki-tomcat', '-s', 'KRA'] returned non-zero exit status 1: 'ERROR   : pkihelper      unable to access security domain. Continuing .. HTTPSConnectionPool(host=\'host-10-0-137-224.ipa.example\', port=443): Max retries exceeded with url: /ca/rest/securityDomain/domainInfo (Caused by NewConnectionError(\'<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa356c3fa50>: Failed to establish a new connection: [Errno 111] Connection refused\')) \nWARNING : pkihelper      this \'KRA\' entry will NOT be deleted from security domain \'IPA\'!\nWARNING : pkihelper      security domain \'IPA\' may be offline or unreachable!\nERROR   : pkihelper      subprocess.CalledProcessError:  Command \'[\'/usr/bin/sslget\', \'-n\', \'subsystemCert cert-pki-ca\', \'-p\', \'5Qm-6%BT}_?|~kC}3]1%E8]S|%0kbazB!3ZD(qcAG\', \'-d\', \'/etc/pki/pki-tomcat/alias\', \'-e\', \'name="/var/lib/pki/pki-tomcat"&type=KRA&list=kraList&host=host-10-0-137-224.ipa.example&sport=443&ncsport=443&adminsport=443&agentsport=443&operation=remove\', \'-v\', \'-r\', \'/ca/agent/ca/updateDomainXML\', \'host-10-0-137-224.ipa.example:443\']\' returned non-zero exit status 6.!\nJob for pki-tomcatd@pki-tomcat.service failed because a timeout was exceeded.\nSee "systemctl status pki-tomcatd@pki-tomcat.service" and "journalctl -xe" for details.\nERROR   : pkidestroy     CalledProcessError: Command \'[\'systemctl\', \'start\', \'pki-tomcatd@pki-tomcat.service\']\' returned non-zero exit status 1.\n  File "/usr/lib/python3.7/site-packages/pki/server/pkidestroy.py", line 268, in main\n    scriptlet.destroy(deployer)\n  File "/usr/lib/python3.7/site-packages/pki/server/deployment/scriptlets/finalization.py", line 93, in destroy\n    instance.start()\n  File "/usr/lib/python3.7/site-packages/pki/server/__init__.py", line 242, in start\n    subprocess.check_call(cmd)\n  File "/usr/lib64/python3.7/subprocess.py", line 347, in check_call\n    raise CalledProcessError(retcode, cmd)\n\n')
Unconfiguring CA
Unconfiguring web server
2019-09-27T13:17:50Z DEBUG args=['/usr/sbin/pkidestroy', '-i', 'pki-tomcat', '-s', 'KRA']
2019-09-27T13:19:22Z DEBUG Process finished, return code=1
2019-09-27T13:19:22Z DEBUG stdout=Uninstallation log: /var/log/pki/pki-kra-destroy.20190927091750.log
Loading deployment configuration from /var/lib/pki/pki-tomcat/kra/registry/kra/deployment.cfg.
WARNING: The 'pki_ssl_server_token' in [KRA] has been deprecated. Use 'pki_sslserver_token' instead.
WARNING: The 'pki_pin' in [DEFAULT] has been deprecated. Use 'pki_server_database_password' instead.
Uninstalling KRA from /var/lib/pki/pki-tomcat.
Uninstallation failed: Command failed: systemctl start pki-tomcatd@pki-tomcat.service
2019-09-27T13:19:22Z DEBUG stderr=ERROR   : pkihelper      unable to access security domain. Continuing .. HTTPSConnectionPool(host='host-10-0-137-224.ipa.example', port=443): Max retries exceeded with url: /ca/rest/securityDomain/domainInfo (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa356c3fa50>: Failed to establish a new connection: [Errno 111] Connection refused')) 
WARNING : pkihelper      this 'KRA' entry will NOT be deleted from security domain 'IPA'!
WARNING : pkihelper      security domain 'IPA' may be offline or unreachable!
ERROR   : pkihelper      subprocess.CalledProcessError:  Command '['/usr/bin/sslget', '-n', 'subsystemCert cert-pki-ca', '-p', '5Qm-6%BT}_?|~kC}3]1%E8]S|%0kbazB!3ZD(qcAG', '-d', '/etc/pki/pki-tomcat/alias', '-e', 'name="/var/lib/pki/pki-tomcat"&type=KRA&list=kraList&host=host-10-0-137-224.ipa.example&sport=443&ncsport=443&adminsport=443&agentsport=443&operation=remove', '-v', '-r', '/ca/agent/ca/updateDomainXML', 'host-10-0-137-224.ipa.example:443']' returned non-zero exit status 6.!
Job for pki-tomcatd@pki-tomcat.service failed because a timeout was exceeded.
See "systemctl status pki-tomcatd@pki-tomcat.service" and "journalctl -xe" for details.
ERROR   : pkidestroy     CalledProcessError: Command '['systemctl', 'start', 'pki-tomcatd@pki-tomcat.service']' returned non-zero exit status 1.
  File "/usr/lib/python3.7/site-packages/pki/server/pkidestroy.py", line 268, in main
    scriptlet.destroy(deployer)
  File "/usr/lib/python3.7/site-packages/pki/server/deployment/scriptlets/finalization.py", line 93, in destroy
    instance.start()
  File "/usr/lib/python3.7/site-packages/pki/server/__init__.py", line 242, in start
    subprocess.check_call(cmd)
  File "/usr/lib64/python3.7/subprocess.py", line 347, in check_call
    raise CalledProcessError(retcode, cmd)
2019-09-27T13:19:22Z CRITICAL failed to uninstall KRA instance CalledProcessError(Command ['/usr/sbin/pkidestroy', '-i', 'pki-tomcat', '-s', 'KRA'] returned non-zero exit status 1: 'ERROR   : pkihelper      unable to access security domain. Continuing .. HTTPSConnectionPool(host=\'host-10-0-137-224.ipa.example\', port=443): Max retries exceeded with url: /ca/rest/securityDomain/domainInfo (Caused by NewConnectionError(\'<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa356c3fa50>: Failed to establish a new connection: [Errno 111] Connection refused\')) \nWARNING : pkihelper      this \'KRA\' entry will NOT be deleted from security domain \'IPA\'!\nWARNING : pkihelper      security domain \'IPA\' may be offline or unreachable!\nERROR   : pkihelper      subprocess.CalledProcessError:  Command \'[\'/usr/bin/sslget\', \'-n\', \'subsystemCert cert-pki-ca\', \'-p\', \'5Qm-6%BT}_?|~kC}3]1%E8]S|%0kbazB!3ZD(qcAG\', \'-d\', \'/etc/pki/pki-tomcat/alias\', \'-e\', \'name="/var/lib/pki/pki-tomcat"&type=KRA&list=kraList&host=host-10-0-137-224.ipa.example&sport=443&ncsport=443&adminsport=443&agentsport=443&operation=remove\', \'-v\', \'-r\', \'/ca/agent/ca/updateDomainXML\', \'host-10-0-137-224.ipa.example:443\']\' returned non-zero exit status 6.!\nJob for pki-tomcatd@pki-tomcat.service failed because a timeout was exceeded.\nSee "systemctl status pki-tomcatd@pki-tomcat.service" and "journalctl -xe" for details.\nERROR   : pkidestroy     CalledProcessError: Command \'[\'systemctl\', \'start\', \'pki-tomcatd@pki-tomcat.service\']\' returned non-zero exit status 1.\n  File "/usr/lib/python3.7/site-packages/pki/server/pkidestroy.py", line 268, in main\n    scriptlet.destroy(deployer)\n  File "/usr/lib/python3.7/site-packages/pki/server/deployment/scriptlets/finalization.py", line 93, in destroy\n    instance.start()\n  File "/usr/lib/python3.7/site-packages/pki/server/__init__.py", line 242, in start\n    subprocess.check_call(cmd)\n  File "/usr/lib64/python3.7/subprocess.py", line 347, in check_call\n    raise CalledProcessError(retcode, cmd)\n\n')
2019-09-27T13:19:22Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'

I guess the problem is caused by the fact that the uninstaller shuts down all services before it calls pkidestroy.

This probably can be closed. The above warnings/errors no longer appear in the latest code:
https://github.com/dogtagpki/pki/actions/runs/5966732892/job/16187864423#step:25:1

Agreed. It is also impacted by 67a33e5a305c7510fb182f84e46f304043f6ab37 which tries to ensure PKI is running during the uninstall specifically so that the security domain removal can occur.

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

Metadata