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 1902173 - Uninstallation of IPA server with KRA installed displays 'ERROR: subprocess.CalledProcessError:'
Summary: Uninstallation of IPA server with KRA installed displays 'ERROR: subprocess.C...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: ipa
Version: 8.4
Hardware: Unspecified
OS: Unspecified
high
unspecified
Target Milestone: rc
: 8.0
Assignee: Thomas Woerner
QA Contact: ipa-qe
URL:
Whiteboard:
: 1481949 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-11-27 08:36 UTC by Sudhir Menon
Modified: 2024-03-25 17:16 UTC (History)
7 users (show)

Fixed In Version: ipa-4.9.2-1
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2021-05-18 15:48:22 UTC
Type: Bug
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github dogtagpki pki issues 2924 0 None open ipaserver uninstall in verbose mode displays "pkidestroy: ERROR.. subprocess.CalledProcessError: returned non-zero exit... 2021-02-15 20:57:28 UTC

Description Sudhir Menon 2020-11-27 08:36:11 UTC 
Description of problem: Uninstallation of IPA server with KRA installed displays 'ERROR: subprocess.CalledProcessError:'


Version-Release number of selected component (if applicable):
ipa-server-4.9.0-0.1.rc1.module+el8.4.0+8830+62cd648b.x86_64
pki-server-10.10.0-0.2.beta1.module+el8.4.0+8460+91b0d519.noarch

How reproducible:
Always

Steps to Reproduce:
1. ipa-server-install --setup-dns --setup-kra
2. Ensure ipa-server is installed successfully
3. Now ipa-server-install --uninstall -U -v

Actual results:
ipa server is installed successfully but when we check the uninstall logs it displays the below error.

2020-11-27T07:20:41Z DEBUG Stop of certmonger.service complete
2020-11-27T07:20:41Z DEBUG Unconfiguring KRA
2020-11-27T07:20:41Z DEBUG Starting external process
2020-11-27T07:20:41Z DEBUG args=['/usr/sbin/pkidestroy', '-i', 'pki-tomcat', '-s', 'KRA']
2020-11-27T07:22:14Z DEBUG Process finished, return code=1
2020-11-27T07:22:14Z DEBUG stdout=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.
Uninstallation log: /var/log/pki/pki-kra-destroy.20201127022041.log
Uninstalling KRA from /var/lib/pki/pki-tomcat.

Uninstallation failed: Command failed: systemctl start pki-tomcatd


2020-11-27T07:22:14Z DEBUG stderr=ERROR: unable to access security domain. Continuing .. HTTPSConnectionPool(host='server1.rhel84.test', port=443): Max retries exceeded with url: /ca/rest/securityDomain/domainInfo (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa24418bc18>: Failed to establish a new connection: [Errno 111] Connection refused',)) 
WARNING: this 'KRA' entry will NOT be deleted from security domain 'IPA'!
WARNING: security domain 'IPA' may be offline or unreachable!
ERROR: subprocess.CalledProcessError:  Command '['/usr/bin/sslget', '-n', 'subsystemCert cert-pki-ca', '-p', '4Ee~PGR>QQo;H-pa(7[eB8C4{_?WK4U9KIWXpWqOK', '-d', '/etc/pki/pki-tomcat/alias', '-e', 'name="/var/lib/pki/pki-tomcat"&type=KRA&list=kraList&host=server1.rhel84.test&sport=443&ncsport=443&adminsport=443&agentsport=443&operation=remove', '-v', '-r', '/ca/agent/ca/updateDomainXML', 'server1.rhel84.test:443']' returned non-zero exit status 6.!
Job for pki-tomcatd failed because a timeout was exceeded.
See "systemctl status pki-tomcatd" and "journalctl -xe" for details.
ERROR: CalledProcessError: Command '['systemctl', 'start', 'pki-tomcatd']' returned non-zero exit status 1.
  File "/usr/lib/python3.6/site-packages/pki/server/pkidestroy.py", line 261, in main
    scriptlet.destroy(deployer)
  File "/usr/lib/python3.6/site-packages/pki/server/deployment/scriptlets/finalization.py", line 90, in destroy
    instance.start()
  File "/usr/lib/python3.6/site-packages/pki/server/__init__.py", line 260, in start
    subprocess.check_call(cmd)
  File "/usr/lib64/python3.6/subprocess.py", line 311, in check_call
    raise CalledProcessError(retcode, cmd)

Expected results:
Fix the CalledProcessError.

Additional info: 
https://pagure.io/freeipa/issue/8550
Attaching the logs for reference.
Comment 1 Florence Blanc-Renaud 2020-11-27 08:49:00 UTC 
Upstream ticket:
https://pagure.io/freeipa/issue/8550
Comment 2 Florence Blanc-Renaud 2020-11-27 21:04:29 UTC 
Investigations:
===============
IPA uninstaller stops all the services then calls "pkidestroy -i pki-tomcat -s KRA". pkidestroy performs the removal of the subsystem and re-starts pki-tomcatd at the end of pkidestroy command (https://github.com/dogtagpki/pki/blob/61297c6f97cb0e850a76307d1200b4a7c63f001c/base/server/python/pki/server/deployment/scriptlets/finalization.py#L88). The startup of the service fails and pki-destroy exits on error.

In RHEL 7.9 the call to pkidestroy prints the same warnings and error messages but pkidestroy exits with 0 (because the restart of the pki-tomcatd service succeeds).
With RHEL 8.4 pkidestroy exits with 1. The change of behavior can be traced to RHEL 8.1 with the introduction of ipa-pki-wait-running script:
when IPA configures a CA or KRA instance, it drops a config file in /etc/systemd/system/pki-tomcatd.d/ipa.conf:
-----
[Service]
ExecStartPost=/usr/libexec/ipa/ipa-pki-wait-running
-----
If the script ipa-pki-wait-running fails, systemd considers pki-tomcatd unit as failed.

The intent of ipa-pki-wait-running is to ensure that other services are not started before the CA is actually up and running (it may take ~10s between the startup and the CA availabity). To do so, ipa-pki-wait-running script tries to establish a connection to pki CA subsystem, but since the all services have been stopped at the beginning of the uninstallation (httpd is not running anymore), it fails. I am not sure why pkidestroy restarts the service even if it was stopped when pkidestroy was invoked.

A possible fix would be for pkidestroy NOT to restart the service if it was not running.
@edewata, what do you think?
Comment 6 Petr Čech 2021-01-06 09:07:36 UTC 
*** Bug 1481949 has been marked as a duplicate of this bug. ***
Comment 7 Petr Čech 2021-01-06 09:18:34 UTC 
*** Bug 1740702 has been marked as a duplicate of this bug. ***
Comment 9 Florence Blanc-Renaud 2021-02-04 00:31:49 UTC 
Fixed upstream
master:
https://pagure.io/freeipa/c/62521edcd17f2d24393377513afc9acb3e397410
https://pagure.io/freeipa/c/daf2ca3ead0f529dd3bcfd2aba97a410638dba7d
https://pagure.io/freeipa/c/928ab51be669d7af7a28205acb9eb7e9b46e189e
https://pagure.io/freeipa/c/1870c933542d41766dd9e2076deb7db758726864
https://pagure.io/freeipa/c/ed21787190382707f9d80559967f71637c8bf408
https://pagure.io/freeipa/c/8082a2d9eb96c4d5471b72e6a008cd273ec743cd
Comment 10 Florence Blanc-Renaud 2021-02-04 13:18:03 UTC 
Fixed upstream
ipa-4-9:
https://pagure.io/freeipa/c/b99bc2d8b1e5226f61a7c980cfb7576dac222466
https://pagure.io/freeipa/c/4d26ce5061c5b7f9383286a108fc48b19b5bc65a
https://pagure.io/freeipa/c/ddb5414d56f57fdd18ad66fbc6a53410725dd9cd
https://pagure.io/freeipa/c/87ede26cc2bcbe543cb970a5e55cf1901791a100
https://pagure.io/freeipa/c/302f9377e5c760bcf38be2b0503915ccadef8b67
https://pagure.io/freeipa/c/00226adaa68935fbc1d85508eadafa420027edb5
Comment 11 Kaleem 2021-02-18 11:42:57 UTC 
Verified based on following info

(1) Following log with reproduced issue which got caught in modified test test_full_backup_reinstall_restore_with_vault in build where issue not fixed


2021-02-18T11:03:08+0000 =========================== short test summary info ============================
2021-02-18T11:03:08+0000 PASSED ipatests/test_integration/test_backup_and_restore.py::TestBackupReinstallRestoreWithKRA::test_no_error_message_with_uninstall_ipa_with_kra
2021-02-18T11:03:08+0000 FAILED ipatests/test_integration/test_backup_and_restore.py::TestBackupReinstallRestoreWithKRA::test_full_backup_reinstall_restore_with_vault
2021-02-18T11:03:08+0000 ============== 1 failed, 1 passed, 1 warning in 786.58s (0:13:06) ==============

IPA Version : 

2021-02-18T10:47:56+0000 TASK [List installed IPA packages version] *************************************
2021-02-18T10:47:56+0000 ok: [master.testrelm.test] => (item=ipa-server) => 
2021-02-18T10:47:56+0000   msg:
2021-02-18T10:47:56+0000   - arch: x86_64
2021-02-18T10:47:56+0000     epoch: null
2021-02-18T10:47:56+0000     name: ipa-server
2021-02-18T10:47:56+0000     release: 1.module+el8.4.0+9665+c9815399
2021-02-18T10:47:56+0000     source: rpm
2021-02-18T10:47:56+0000     version: 4.9.1

(2) Issue not reproduced with build where issue got fixed 

test compose used : http://artifacts.osci.redhat.com/comp/rhel-8.4.0-mbs/9973-1386-idm/ 

2021-02-18T11:23:41+0000 =========================== short test summary info ============================
2021-02-18T11:23:41+0000 PASSED ipatests/test_integration/test_backup_and_restore.py::TestBackupReinstallRestoreWithKRA::test_full_backup_reinstall_restore_with_vault
2021-02-18T11:23:41+0000 PASSED ipatests/test_integration/test_backup_and_restore.py::TestBackupReinstallRestoreWithKRA::test_no_error_message_with_uninstall_ipa_with_kra
2021-02-18T11:23:41+0000 ================== 2 passed, 1 warning in 1263.47s (0:21:03) ===================


IPA Version :

2021-02-18T11:00:23+0000 TASK [List installed IPA packages version] *************************************
2021-02-18T11:00:23+0000 ok: [master.testrelm.test] => (item=ipa-server) => 
2021-02-18T11:00:23+0000   msg:
2021-02-18T11:00:23+0000   - arch: x86_64
2021-02-18T11:00:23+0000     epoch: null
2021-02-18T11:00:23+0000     name: ipa-server
2021-02-18T11:00:23+0000     release: 1.module+el8.4.0+9973+3d202164
2021-02-18T11:00:23+0000     source: rpm
2021-02-18T11:00:23+0000     version: 4.9.2
Comment 14 Florence Blanc-Renaud 2021-02-18 15:46:51 UTC 
Test added upstream in test_integration/test_backup_and_restore.py::TestBackupReinstallRestoreWithKRA::test_no_error_message_with_uninstall_ipa_with_kra

master:
https://pagure.io/freeipa/c/5e49910bcf015f14533cfd7a788364aba7a7cbd3
Comment 15 Florence Blanc-Renaud 2021-02-19 07:42:45 UTC 
Fixed upstream
ipa-4-9:
https://pagure.io/freeipa/c/6b25cd3241a5609b4d903d5697b8947fab403c90
Comment 16 Kaleem 2021-02-19 10:07:04 UTC 
Verified using nightly compose RHEL-8.4.0-20210218.n.0

IPA Version:
------------

2021-02-19T09:24:16+0000 TASK [List installed IPA packages version] *************************************
2021-02-19T09:24:17+0000 ok: [master.testrelm.test] => (item=ipa-server) => 
2021-02-19T09:24:17+0000   msg:
2021-02-19T09:24:17+0000   - arch: x86_64
2021-02-19T09:24:17+0000     epoch: null
2021-02-19T09:24:17+0000     name: ipa-server
2021-02-19T09:24:17+0000     release: 1.module+el8.4.0+9973+3d202164
2021-02-19T09:24:17+0000     source: rpm
2021-02-19T09:24:17+0000     version: 4.9.2

Tests summary :
---------------
2021-02-19T09:47:55+0000 ------------- generated html file: file:///tmp/wp/twd/report.html --------------
2021-02-19T09:47:55+0000 =========================== short test summary info ============================
2021-02-19T09:47:55+0000 PASSED ipatests/test_integration/test_backup_and_restore.py::TestBackupReinstallRestoreWithKRA::test_full_backup_reinstall_restore_with_vault
2021-02-19T09:47:55+0000 PASSED ipatests/test_integration/test_backup_and_restore.py::TestBackupReinstallRestoreWithKRA::test_no_error_message_with_uninstall_ipa_with_kra
2021-02-19T09:47:55+0000 ================== 2 passed, 1 warning in 1296.98s (0:21:36) ===================
Comment 18 errata-xmlrpc 2021-05-18 15:48:22 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 (Moderate: idm:DL1 and idm:client security, bug fix, and enhancement update), 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-2021:1846
Note You need to log in before you can comment on or make changes to this bug.