Bug 1817918

Summary: Secure tomcat AJP connector
Product: Red Hat Enterprise Linux 7 Reporter: Florence Blanc-Renaud <frenaud>
Component: ipaAssignee: Florence Blanc-Renaud <frenaud>
Status: CLOSED ERRATA QA Contact: ipa-qe <ipa-qe>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.9CC: abokovoy, amore, extras-qa, frenaud, ipa-maint, jcholast, jhrozek, jpazdziora, ksiddiqu, pvoborni, rcritten, ssidhaye, ssorce, tscherf, twoerner
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: ipa-4.6.8-1.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1812169 Environment:
Last Closed: 2020-09-29 19:59:24 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1812169    
Bug Blocks:    

Description Florence Blanc-Renaud 2020-03-27 08:42:00 UTC 
+++ This bug was initially created as a clone of Bug #1812169 +++

Description of problem:

On Fedora 32 and rawhide, running ipa-replica-install fails with
Certificate issuance failed (CA_UNREACHABLE: Server at https://ipa-master.example.test/ipa/xml failed request, will retry: 4016 (RPC failed at server.  Failed to authenticate to CA REST API).)

Version-Release number of selected component (if applicable):

freeipa-server-4.8.4-8.fc33.x86_64

How reproducible:

Deterministic.

Steps to Reproduce:
1. Have IPA master setup with
   ipa-server-install -U -r EXAMPLE.TEST --setup-dns --no-forwarders --no-ntp -p Secret123 -a Secret123
2. Edit /etc/resolv.conf for the nameserver to point to the IPA master machine.
3. On the replica machine, run
   ipa-replica-install -U --skip-conncheck --principal admin --setup-ca --no-ntp --principal admin --admin-password=Secret123

Actual results:

  [26/41]: creating DS keytab
  [27/41]: ignore time skew for initial replication
  [28/41]: setting up initial replication
Starting replication, please wait until this has completed.
Update in progress, 4 seconds elapsed
Update succeeded

  [29/41]: prevent time skew after initial replication
  [30/41]: adding sasl mappings to the directory
  [31/41]: updating schema
  [32/41]: setting Auto Member configuration
  [33/41]: enabling S4U2Proxy delegation
  [34/41]: initializing group membership
  [35/41]: adding master entry
  [36/41]: initializing domain level
  [37/41]: configuring Posix uid/gid generation
  [38/41]: adding replication acis
  [39/41]: activating sidgen plugin
  [40/41]: activating extdom plugin
  [41/41]: configuring directory to start on boot
Done configuring directory server (dirsrv).
Configuring Kerberos KDC (krb5kdc)
  [1/5]: configuring KDC
  [2/5]: adding the password extension to the directory
  [3/5]: creating anonymous principal
  [4/5]: starting the KDC
  [5/5]: configuring KDC to start on boot
Done configuring Kerberos KDC (krb5kdc).
Configuring kadmin
  [1/2]: starting kadmin 
  [2/2]: configuring kadmin to start on boot
Done configuring kadmin.
Configuring directory server (dirsrv)
  [1/3]: configuring TLS for DS instance
  [error] RuntimeError: Certificate issuance failed (CA_UNREACHABLE: Server at https://ipa-master.example.test/ipa/xml failed request, will retry: 4016 (RPC failed at server.  Failed to authenticate to CA REST API).)
Your system may be partly configured.
Run /usr/sbin/ipa-server-install --uninstall to clean up.

Certificate issuance failed (CA_UNREACHABLE: Server at https://ipa-master.example.test/ipa/xml failed request, will retry: 4016 (RPC failed at server.  Failed to authenticate to CA REST API).)
The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information

Expected results:

No error, IPA replica setup.

Additional info:

The ipareplica-install.log ends with

2020-03-10T16:58:16Z DEBUG step duration: kadmin __enable 0.21 sec
2020-03-10T16:58:16Z DEBUG Done configuring kadmin.
2020-03-10T16:58:16Z DEBUG service duration: kadmin 0.34 sec
2020-03-10T16:58:16Z DEBUG Backing up system configuration file '/etc/ipa/default.conf'
2020-03-10T16:58:16Z DEBUG Saving Index File to '/var/lib/ipa/sysrestore/sysrestore.index'
2020-03-10T16:58:16Z DEBUG Writing configuration file /etc/ipa/default.conf
2020-03-10T16:58:16Z DEBUG [global]
basedn = dc=example,dc=test
host = ipa-replica2.example.test
realm = EXAMPLE.TEST
domain = example.test
xmlrpc_uri = https://ipa-master.example.test/ipa/xml
ldap_uri = ldapi://%2Fvar%2Frun%2Fslapd-EXAMPLE-TEST.socket
mode = production
enable_ra = True
ra_plugin = dogtag
dogtag_version = 10



2020-03-10T16:58:16Z DEBUG Configuring directory server (dirsrv)
2020-03-10T16:58:16Z DEBUG   [1/3]: configuring TLS for DS instance
2020-03-10T16:58:16Z DEBUG Loading Index file from '/var/lib/ipa/sysrestore/sysrestore.index'
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/usr/bin/certutil', '-d', 'sql:/etc/dirsrv/slapd-EXAMPLE-TEST/', '-L', '-n', 'EXAMPLE.TEST IPA CA', '-a', '-f', '/etc/dirsrv/slapd-EXAMPLE-TEST/pwdfile.txt']
2020-03-10T16:58:16Z DEBUG Process finished, return code=255
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=certutil: Could not find cert: EXAMPLE.TEST IPA CA
: PR_FILE_NOT_FOUND_ERROR: File not found

2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/usr/bin/certutil', '-d', 'sql:/etc/dirsrv/slapd-EXAMPLE-TEST/', '-N', '-f', '/etc/dirsrv/slapd-EXAMPLE-TEST/pwdfile.txt', '-@', '/etc/dirsrv/slapd-EXAMPLE-TEST/pwdfile.txt']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/usr/sbin/selinuxenabled']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/sbin/restorecon', '-F', '/etc/dirsrv/slapd-EXAMPLE-TEST/']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/usr/sbin/selinuxenabled']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/sbin/restorecon', '-F', '/etc/dirsrv/slapd-EXAMPLE-TEST/cert9.db']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/usr/sbin/selinuxenabled']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/sbin/restorecon', '-F', '/etc/dirsrv/slapd-EXAMPLE-TEST/key4.db']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/usr/sbin/selinuxenabled']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/sbin/restorecon', '-F', '/etc/dirsrv/slapd-EXAMPLE-TEST/pkcs11.txt']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/usr/sbin/selinuxenabled']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/sbin/restorecon', '-F', '/etc/dirsrv/slapd-EXAMPLE-TEST/pwdfile.txt']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG Starting external process
2020-03-10T16:58:16Z DEBUG args=['/usr/bin/certutil', '-d', 'sql:/etc/dirsrv/slapd-EXAMPLE-TEST/', '-A', '-n', 'EXAMPLE.TEST IPA CA', '-t', 'CT,C,C', '-a', '-f', '/etc/dirsrv/slapd-EXAMPLE-TEST/pwdfile.txt']
2020-03-10T16:58:16Z DEBUG Process finished, return code=0
2020-03-10T16:58:16Z DEBUG stdout=
2020-03-10T16:58:16Z DEBUG stderr=
2020-03-10T16:58:16Z DEBUG certmonger request is in state dbus.String('NEWLY_ADDED_READING_KEYINFO', variant_level=1)
2020-03-10T16:58:21Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:58:26Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:58:31Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:58:36Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:58:41Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:58:46Z DEBUG wait_for_request raised request timed out
2020-03-10T16:58:46Z DEBUG Cert request 20200310165816 failed: TIMEOUT (None)
2020-03-10T16:58:46Z DEBUG 20200310165816 not in final state, continue waiting
2020-03-10T16:58:56Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:59:01Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:59:06Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:59:11Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:59:16Z DEBUG certmonger request is in state dbus.String('SUBMITTING', variant_level=1)
2020-03-10T16:59:21Z DEBUG certmonger request is in state dbus.String('CA_UNREACHABLE', variant_level=1)
2020-03-10T16:59:21Z DEBUG Cert request 20200310165816 failed: CA_UNREACHABLE (Server at https://ipa-master.example.test/ipa/xml failed request, will retry: 4016 (RPC failed at server.  Failed to authenticate to CA REST API).)
2020-03-10T16:59:21Z DEBUG Giving up on cert request 20200310165816
2020-03-10T16:59:21Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 603, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 589, in run_step
    method()
  File "/usr/lib/python3.8/site-packages/ipaserver/install/dsinstance.py", line 864, in __enable_ssl
    certmonger.request_and_wait_for_cert(
  File "/usr/lib/python3.8/site-packages/ipalib/install/certmonger.py", line 365, in request_and_wait_for_cert
    raise RuntimeError(
RuntimeError: Certificate issuance failed (CA_UNREACHABLE: Server at https://ipa-master.example.test/ipa/xml failed request, will retry: 4016 (RPC failed at server.  Failed to authenticate to CA REST API).)

2020-03-10T16:59:21Z DEBUG   [error] RuntimeError: Certificate issuance failed (CA_UNREACHABLE: Server at https://ipa-master.example.test/ipa/xml failed request, will retry: 4016 (RPC failed at server.  Failed to authenticate to CA REST API).)
2020-03-10T16:59:21Z DEBUG   File "/usr/lib/python3.8/site-packages/ipapython/admintool.py", line 179, in execute
    return_value = self.run()
  File "/usr/lib/python3.8/site-packages/ipapython/install/cli.py", line 340, in run
    return cfgr.run()
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 360, in run
    return self.execute()
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 386, in execute
    for rval in self._executor():
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.8/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 655, in _configure
    next(executor)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 518, in _handle_exception
    self.__parent._handle_exception(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 515, in _handle_exception
    super(ComponentBase, self)._handle_exception(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.8/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.8/site-packages/ipapython/install/common.py", line 65, in _install
    for unused in self._installer(self.parent):
  File "/usr/lib/python3.8/site-packages/ipaserver/install/server/__init__.py", line 597, in main
    replica_install(self)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/server/replicainstall.py", line 402, in decorated
    func(installer)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/server/replicainstall.py", line 1285, in install
    ds.enable_ssl()
  File "/usr/lib/python3.8/site-packages/ipaserver/install/dsinstance.py", line 330, in enable_ssl
    self.start_creation()
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 603, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 589, in run_step
    method()
  File "/usr/lib/python3.8/site-packages/ipaserver/install/dsinstance.py", line 864, in __enable_ssl
    certmonger.request_and_wait_for_cert(
  File "/usr/lib/python3.8/site-packages/ipalib/install/certmonger.py", line 365, in request_and_wait_for_cert
    raise RuntimeError(

2020-03-10T16:59:21Z DEBUG The ipa-replica-install command failed, exception: RuntimeError: Certificate issuance failed (CA_UNREACHABLE: Server at https://ipa-master.example.test/ipa/xml failed request, will retry: 4016 (RPC failed at server.  Failed to authenticate to CA REST API).)
2020-03-10T16:59:21Z ERROR Certificate issuance failed (CA_UNREACHABLE: Server at https://ipa-master.example.test/ipa/xml failed request, will retry: 4016 (RPC failed at server.  Failed to authenticate to CA REST API).)
2020-03-10T16:59:21Z ERROR The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information

--- Additional comment from Jan Pazdziora on 2020-03-10 17:01:32 UTC ---

I see the same failure on Fedora 32.

--- Additional comment from Alexander Bokovoy on 2020-03-10 17:15:44 UTC ---

What tomcat version do you have?

In rawhide it is a known issue with tomcat 9.0.31 which enforces use of a secret-protected setup for AJP proxy. I'm currently working on a fix for upstream.

--- Additional comment from Jan Pazdziora on 2020-03-10 17:17:24 UTC ---

It's tomcat-9.0.31-1.fc33.noarch.

--- Additional comment from Alexander Bokovoy on 2020-03-10 21:42:24 UTC ---

Upstream PR: https://github.com/freeipa/freeipa/pull/4337

--- Additional comment from Florence Blanc-Renaud on 2020-03-11 16:53:58 UTC ---

Fixed upstream
master:
https://pagure.io/freeipa/c/593fac1ca9381a51ee59fac994d818ed9619bd8e
https://pagure.io/freeipa/c/ec73de969f55b7a005b6401029f87fe6a225a417

--- Additional comment from Florence Blanc-Renaud on 2020-03-12 06:53:48 UTC ---

Fixed upstream
ipa-4-8:
https://pagure.io/freeipa/c/1deb1010b245df6c363c5655f9a548bdf4dbc040
https://pagure.io/freeipa/c/d4d8b98c3588b212db6a26610e690cccb3af84ca

ipa-4-7:
https://pagure.io/freeipa/c/d4ad2c24df2477a5b4ced14a592d99547a0c029e
https://pagure.io/freeipa/c/fc82b966c054b8a6a98441f08d9ccf2f5737e623

ipa-4-6:
https://pagure.io/freeipa/c/af2dca13d0cc24e0cf32bc23e4edb86fbbf60d03
https://pagure.io/freeipa/c/901d0eca7d462c74c1664aae9b3415ede7ba3dfc

--- Additional comment from Lukas Slebodnik on 2020-03-16 16:05:38 UTC ---

(In reply to Florence Blanc-Renaud from comment #6)
> Fixed upstream
> ipa-4-8:
> https://pagure.io/freeipa/c/1deb1010b245df6c363c5655f9a548bdf4dbc040
> https://pagure.io/freeipa/c/d4d8b98c3588b212db6a26610e690cccb3af84ca
> 

Backporting these patches does not seems to be enough for rawhide.

The installation on master will fails

Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes
  [1/30]: configuring certificate server instance
Failed to configure CA instance: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpchj5vgwk'] returned non-zero exit status 1: 'Notice: Trust flag u is set automatically if the private key is present.\nERROR: CalledProcessError: Command \'[\'sudo\', \'-u\', \'pkiuser\', \'/usr/lib/jvm/jre-1.8.0-openjdk/bin/java\', \'-classpath\', \'/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/*\', \'-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory\', \'-Dcatalina.base=/var/lib/pki/pki-tomcat\', \'-Dcatalina.home=/usr/share/tomcat\', \'-Djava.endorsed.dirs=\', \'-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp\', \'-Djava.util.logging.config.file=/etc/pki/pki-tomcat/logging.properties\', \'-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager\', \'org.dogtagpki.server.cli.PKIServerCLI\', \'ca-db-remove\', \'--force\']\' died with <Signals.SIGABRT: 6>.\n  File "/usr/lib/python3.8/site-packages/pki/server/pkispawn.py", line 562, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.8/site-packages/pki/server/deployment/scriptlets/configuration.py", line 747, in spawn\n    subsystem.remove_database(force=True)\n  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 932, in remove_database\n    self.run(cmd, as_current_user=as_current_user)\n  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 980, in run\n    subprocess.run(cmd, check=True)\n  File "/usr/lib64/python3.8/subprocess.py", line 512, in run\n    raise CalledProcessError(retcode, process.args,\n\n')
See the installation logs and the following files/directories for more information:
  /var/log/pki/pki-tomcat
  [error] RuntimeError: CA configuration failed.
CA configuration failed.

--- Additional comment from Lukas Slebodnik on 2020-03-16 16:09:50 UTC ---

For some reason jdk crashed

2020-03-16T12:18:37Z DEBUG Starting external process
2020-03-16T12:18:37Z DEBUG args=['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpchj5vgwk']
2020-03-16T12:18:43Z DEBUG Process finished, return code=1
2020-03-16T12:18:43Z DEBUG stdout=#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007fba2b65afbe, pid=24003, tid=0x00007fba2904a700
#
# JRE version: OpenJDK Runtime Environment (8.0_242-b08) (build 1.8.0_242-b08)
# Java VM: OpenJDK 64-Bit Server VM (25.242-b08 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# V  [libjvm.so+0x701fbe]  JNIHandleBlock::oops_do(OopClosure*)+0xae
#
# Core dump written. Default location: /tmp/hsperfdata_pkiuser/core or core.24003
#
# An error report file with more information is saved as:
# /tmp/hsperfdata_pkiuser/hs_err_pid24003.log
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#
Installation log: /var/log/pki/pki-ca-spawn.20200316131837.log
Loading deployment configuration from /tmp/tmpchj5vgwk.
WARNING: The 'pki_ssl_server_token' in [CA] has been deprecated. Use 'pki_sslserver_token' instead.
Installing CA into /var/lib/pki/pki-tomcat.

Installation failed: Command failed: sudo -u pkiuser /usr/lib/jvm/jre-1.8.0-openjdk/bin/java -classpath /usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/
share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/* -Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory -Dcatalina.b
ase=/var/lib/pki/pki-tomcat -Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp -Djava.util.logging.config.file=/etc/pki/pki-tomcat/logg
ing.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager org.dogtagpki.server.cli.PKIServerCLI ca-db-remove --force

Please check pkispawn logs in /var/log/pki/pki-ca-spawn.20200316131837.log

2020-03-16T12:18:43Z DEBUG stderr=Notice: Trust flag u is set automatically if the private key is present.
ERROR: CalledProcessError: Command '['sudo', '-u', 'pkiuser', '/usr/lib/jvm/jre-1.8.0-openjdk/bin/java', '-classpath', '/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/*', '-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory', '-Dcatalina.base=/var/lib/pki/pki-tomcat', '-Dcatalina.home=/usr/share/tomcat', '-Djava.endorsed.dirs=', '-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp', '-Djava.util.logging.config.file=/etc/pki/pki-tomcat/logging.properties', '-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager', 'org.dogtagpki.server.cli.PKIServerCLI', 'ca-db-remove', '--force']' died with <Signals.SIGABRT: 6>.
  File "/usr/lib/python3.8/site-packages/pki/server/pkispawn.py", line 562, in main
    scriptlet.spawn(deployer)
  File "/usr/lib/python3.8/site-packages/pki/server/deployment/scriptlets/configuration.py", line 747, in spawn
    subsystem.remove_database(force=True)
  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 932, in remove_database
    self.run(cmd, as_current_user=as_current_user)
  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 980, in run
    subprocess.run(cmd, check=True)
  File "/usr/lib64/python3.8/subprocess.py", line 512, in run
    raise CalledProcessError(retcode, process.args,



2020-03-16T12:18:43Z CRITICAL Failed to configure CA instance: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpchj5vgwk'] returned non-zero exit status 1: 'Notice: Trust flag u is set automatically if the private key is present.\nERROR: CalledProcessError: Command \'[\'sudo\', \'-u\', \'pkiuser\', \'/usr/lib/jvm/jre-1.8.0-openjdk/bin/java\', \'-classpath\', \'/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/*\', \'-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory\', \'-Dcatalina.base=/var/lib/pki/pki-tomcat\', \'-Dcatalina.home=/usr/share/tomcat\', \'-Djava.endorsed.dirs=\', \'-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp\', \'-Djava.util.logging.config.file=/etc/pki/pki-tomcat/logging.properties\', \'-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager\', \'org.dogtagpki.server.cli.PKIServerCLI\', \'ca-db-remove\', \'--force\']\' died with <Signals.SIGABRT: 6>.\n  File "/usr/lib/python3.8/site-packages/pki/server/pkispawn.py", line 562, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.8/site-packages/pki/server/deployment/scriptlets/configuration.py", line 747, in spawn\n    subsystem.remove_database(force=True)\n  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 932, in remove_database\n    self.run(cmd, as_current_user=as_current_user)\n  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 980, in run\n    subprocess.run(cmd, check=True)\n  File "/usr/lib64/python3.8/subprocess.py", line 512, in run\n    raise CalledProcessError(retcode, process.args,\n\n')
2020-03-16T12:18:43Z CRITICAL See the installation logs and the following files/directories for more information:
2020-03-16T12:18:43Z CRITICAL   /var/log/pki/pki-tomcat
2020-03-16T12:18:43Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/ipaserver/install/dogtaginstance.py", line 193, in spawn_instance
    ipautil.run(args, nolog=nolog_list)
  File "/usr/lib/python3.8/site-packages/ipapython/ipautil.py", line 597, in run
    raise CalledProcessError(
ipapython.ipautil.CalledProcessError: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpchj5vgwk'] returned non-zero exit status 1: 'Notice: Trust flag u is set automatically if the private key is present.\nERROR: CalledProcessError: Command \'[\'sudo\', \'-u\', \'pkiuser\', \'/usr/lib/jvm/jre-1.8.0-openjdk/bin/java\', \'-classpath\', \'/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/*\', \'-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory\', \'-Dcatalina.base=/var/lib/pki/pki-tomcat\', \'-Dcatalina.home=/usr/share/tomcat\', \'-Djava.endorsed.dirs=\', \'-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp\', \'-Djava.util.logging.config.file=/etc/pki/pki-tomcat/logging.properties\', \'-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager\', \'org.dogtagpki.server.cli.PKIServerCLI\', \'ca-db-remove\', \'--force\']\' died with <Signals.SIGABRT: 6>.\n  File "/usr/lib/python3.8/site-packages/pki/server/pkispawn.py", line 562, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.8/site-packages/pki/server/deployment/scriptlets/configuration.py", line 747, in spawn\n    subsystem.remove_database(force=True)\n  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 932, in remove_database\n    self.run(cmd, as_current_user=as_current_user)\n  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 980, in run\n    subprocess.run(cmd, check=True)\n  File "/usr/lib64/python3.8/subprocess.py", line 512, in run\n    raise CalledProcessError(retcode, process.args,\n\n')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 603, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 589, in run_step
    method()
  File "/usr/lib/python3.8/site-packages/ipaserver/install/cainstance.py", line 596, in __spawn_instance
    DogtagInstance.spawn_instance(
  File "/usr/lib/python3.8/site-packages/ipaserver/install/dogtaginstance.py", line 195, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/dogtaginstance.py", line 503, in handle_setup_error
    raise RuntimeError("%s configuration failed." % self.subsystem)
RuntimeError: CA configuration failed.

--- Additional comment from Florence Blanc-Renaud on 2020-03-16 16:50:12 UTC ---

Hi Lukas,
the issue you mention is a different one, already reported in https://pagure.io/dogtagpki/issue/3130 ipa-server-install fails in pkispawn step with a java coredump.
The above ticket mentions https://bugzilla.redhat.com/show_bug.cgi?id=1813550 java segmentation faults during package builds in rawhide which is a java-1.8.0-openjdk problem.

Is it OK for you to move back this BZ to POST?

--- Additional comment from Lukas Slebodnik on 2020-03-17 08:52:14 UTC ---

Last time when I tried, I was able to install at least master without patch (just replica failed)
But I failed to install even maser with patch. I did not dive into details but
it seems suspicious for me.

If you are sure it is unrelated then feel free to move to POST
otherwise I would prefer at lest something functional in rawhide.

--- Additional comment from Jan Pazdziora on 2020-03-19 07:52:45 UTC ---

Is it expected that the Java segfault issue seems non-deterministic?
Comment 4 Florence Blanc-Renaud 2020-03-27 08:44:34 UTC 
Not a regression in RHEL 7 as tomcat 9 is not delivered in RHEL7.
Comment 5 Florence Blanc-Renaud 2020-03-27 09:08:22 UTC 
Clearing needinfo as it was automatically added during the cloning of this BZ
Comment 11 anuja 2020-04-14 08:38:33 UTC 
Verified using version: 
ipa-server-4.6.8-1.el7.x86_64
-------------------------------------------------------------------
[root@replica1 ~]# date ; tail -n 1 /var/log/ipareplica-install.log 
Tue Apr 14 04:26:47 EDT 2020
2020-04-14T08:25:49Z INFO The ipa-replica-install command was successful
[root@replica1 ~]# echo Secret123 | kinit admin
Password for admin: 
[root@replica1 ~]# ipactl status
Directory Service: RUNNING
krb5kdc Service: RUNNING
kadmin Service: RUNNING
httpd Service: RUNNING
ipa-custodia Service: RUNNING
pki-tomcatd Service: RUNNING
ipa-otpd Service: RUNNING
ipa: INFO: The ipactl command was successful
[root@replica1 ~]# ipactl restart
Restarting Directory Service
Restarting krb5kdc Service
Restarting kadmin Service
Restarting httpd Service
Restarting ipa-custodia Service
Restarting pki-tomcatd Service
Restarting ipa-otpd Service
ipa: INFO: The ipactl command was successful
[root@replica1 ~]# 

As replica is installed successfully marking bz as verified.
Comment 13 errata-xmlrpc 2020-09-29 19:59:24 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: ipa 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-2020:3936