Bug 1435710

Summary: pki-tomcatd fails to start during ipa-ca-install on a replica
Product: Red Hat Enterprise Linux 7 Reporter: sebastien.ducloux
Component: ipaAssignee: IPA Maintainers <ipa-maint>
Status: CLOSED DUPLICATE QA Contact: ipa-qe <ipa-qe>
Severity: high Docs Contact:
Priority: unspecified    
Version: 7.3CC: arubin, fbarreto, gparente, lkrispen, mbasti, mharmsen, mreynolds, nkinder, pvoborni, rcritten, sebastien.ducloux, striker, tscherf
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-05-02 14:55:40 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
ipareplica-ca-install.log
none
/var/log/pki/pki-tomcat/ca/debug
none
/var/log/pki/pki-tomcat/ca/selftests.log
none
/var/log/pki/pki-ca-spawn.20170323171403.log
none
journalctl -u pki-tomcatd@pki-tomcat.service --no-pager on replica none

Description sebastien.ducloux 2017-03-24 15:06:17 UTC 
Created attachment 1266134 [details]
ipareplica-ca-install.log

Description of problem:
The service pki-tomcatd does not start correctly during ipa-ca-install on an ipa replica so the CA installation is stalled on step '[9/25]: importing CA chain to RA certificate database'.
Same result with reinstallation of entire replica with --setup-ca option.
At this step the service pki-tomcatd is considered as active by systemd, the service listens ports 8080 and 8043. But HTTP POST/GET on /ca/admin/ca/getStatus service timeout with no response. The TCP flows has been however established (so no firewall/selinux problem)
Then I have to kill install process to stop it even after several hours.

The catalina logs are empty.
I cannot see any  error clue on pki-tomcat/ca/debug .
I don't know what the pki-tomcat is waiting for : strace shows nothing when starting this tomcat instance with it.

The CA master works pretty well with same software version.

Version-Release number of selected component (if applicable):
Centos 7.3
krb5-pkinit-1.14.1-27.el7_3.x86_64
pki-tools-10.3.3-17.el7_3.x86_64
pki-ca-10.3.3-17.el7_3.noarch
pki-base-java-10.3.3-17.el7_3.noarch
pki-base-10.3.3-17.el7_3.noarch
pki-server-10.3.3-17.el7_3.noarch
pki-symkey-10.3.3-17.el7_3.x86_64
pki-kra-10.3.3-17.el7_3.noarch
libipa_hbac-1.14.0-43.el7_3.11.x86_64
ipa-admintools-4.4.0-14.el7.centos.6.noarch
sssd-ipa-1.14.0-43.el7_3.11.x86_64
ipa-common-4.4.0-14.el7.centos.6.noarch
ipa-client-4.4.0-14.el7.centos.6.x86_64
ipa-server-dns-4.4.0-14.el7.centos.6.noarch
python2-ipaclient-4.4.0-14.el7.centos.6.noarch
python-iniparse-0.4-9.el7.noarch
python-libipa_hbac-1.14.0-43.el7_3.11.x86_64
python-ipaddress-1.0.16-2.el7.noarch
ipa-client-common-4.4.0-14.el7.centos.6.noarch
python2-ipalib-4.4.0-14.el7.centos.6.noarch
ipa-server-4.4.0-14.el7.centos.6.x86_64
ipa-server-common-4.4.0-14.el7.centos.6.noarch
python2-ipaserver-4.4.0-14.el7.centos.6.noarch



How reproducible:
everytime I test ipa-ca-install on this ipa replica instance.

Steps to Reproduce:
1. ipa-ca-install /var/lib/ipa/*****.gpg

Actual results:
CA Clone install is not completed and pki is not working

Expected results:
CA Clone install completed and pki fully working

Additional info:
pki CLI returns no result because it uses not working HTTP/HTTPS API
Comment 2 sebastien.ducloux 2017-03-24 15:08:00 UTC 
Created attachment 1266149 [details]
/var/log/pki/pki-tomcat/ca/debug
Comment 3 sebastien.ducloux 2017-03-24 15:08:48 UTC 
Created attachment 1266150 [details]
/var/log/pki/pki-tomcat/ca/selftests.log
Comment 4 Petr Vobornik 2017-03-24 15:59:15 UTC 
Could you attach /var/log/ipareplica-ca-install.log , pkispawn log and command output?

The two logs from above are from master or replica?  Do CA logs from master show something interesting?
Comment 5 sebastien.ducloux 2017-03-24 16:22:11 UTC 
Created attachment 1266191 [details]
/var/log/pki/pki-ca-spawn.20170323171403.log
Comment 6 sebastien.ducloux 2017-03-24 16:34:00 UTC 
/var/log/ipareplica-ca-install.log has been already attached : it is the first attachment

All log above is from replica.I added the pkispawn log.

What kind of log do you need from master ?

command output:

ipa-ca-install /var/lib/ipa/replica-info-ds02.lbg.office.fr.lyra.gpg -d
ipa         : DEBUG    /usr/sbin/ipa-ca-install was invoked with options: {'external_cert_files': None, 'skip_schema_check': False, 'external_ca_type': None, 'unattended': False, o_host_dns': False, 'ca_signing_algorithm': None, 'debug': True, 'external_ca': False, 'skip_conncheck': False},/var/lib/ipa/replica-info-ds02.lbg.office.fr.lyra.gpg
ipa         : DEBUG    IPA version 4.4.0-14.el7.centos.6
ipa         : DEBUG    importing all plugin modules in ipaserver.plugins...
ipa         : DEBUG    importing plugin module ipaserver.plugins.aci
ipa         : DEBUG    importing plugin module ipaserver.plugins.automember
ipa         : DEBUG    importing plugin module ipaserver.plugins.automount
ipa         : DEBUG    importing plugin module ipaserver.plugins.baseldap
ipa         : DEBUG    ipaserver.plugins.baseldap is not a valid plugin module
ipa         : DEBUG    importing plugin module ipaserver.plugins.baseuser
ipa         : DEBUG    importing plugin module ipaserver.plugins.batch
ipa         : DEBUG    importing plugin module ipaserver.plugins.ca
ipa         : DEBUG    importing plugin module ipaserver.plugins.caacl
ipa         : DEBUG    importing plugin module ipaserver.plugins.cert
ipa         : DEBUG    importing plugin module ipaserver.plugins.certprofile
ipa         : DEBUG    importing plugin module ipaserver.plugins.config
ipa         : DEBUG    importing plugin module ipaserver.plugins.delegation
ipa         : DEBUG    importing plugin module ipaserver.plugins.dns
ipa         : DEBUG    importing plugin module ipaserver.plugins.dnsserver
ipa         : DEBUG    importing plugin module ipaserver.plugins.dogtag
ipa         : DEBUG    importing plugin module ipaserver.plugins.domainlevel
ipa         : DEBUG    importing plugin module ipaserver.plugins.group
ipa         : DEBUG    importing plugin module ipaserver.plugins.hbac
ipa         : DEBUG    ipaserver.plugins.hbac is not a valid plugin module
ipa         : DEBUG    importing plugin module ipaserver.plugins.hbacrule
ipa         : DEBUG    importing plugin module ipaserver.plugins.hbacsvc
ipa         : DEBUG    importing plugin module ipaserver.plugins.hbacsvcgroup
ipa         : DEBUG    importing plugin module ipaserver.plugins.hbactest
ipa         : DEBUG    importing plugin module ipaserver.plugins.host
ipa         : DEBUG    importing plugin module ipaserver.plugins.hostgroup
ipa         : DEBUG    importing plugin module ipaserver.plugins.idrange
ipa         : DEBUG    importing plugin module ipaserver.plugins.idviews
ipa         : DEBUG    importing plugin module ipaserver.plugins.internal
ipa         : DEBUG    importing plugin module ipaserver.plugins.join
ipa         : DEBUG    importing plugin module ipaserver.plugins.krbtpolicy
ipa         : DEBUG    importing plugin module ipaserver.plugins.ldap2
ipa         : DEBUG    importing plugin module ipaserver.plugins.location
ipa         : DEBUG    importing plugin module ipaserver.plugins.migration
ipa         : DEBUG    importing plugin module ipaserver.plugins.misc
ipa         : DEBUG    importing plugin module ipaserver.plugins.netgroup
ipa         : DEBUG    importing plugin module ipaserver.plugins.otp
ipa         : DEBUG    ipaserver.plugins.otp is not a valid plugin module
ipa         : DEBUG    importing plugin module ipaserver.plugins.otpconfig
ipa         : DEBUG    importing plugin module ipaserver.plugins.otptoken
ipa         : DEBUG    importing plugin module ipaserver.plugins.passwd
ipa         : DEBUG    importing plugin module ipaserver.plugins.permission
ipa         : DEBUG    importing plugin module ipaserver.plugins.ping
ipa         : DEBUG    importing plugin module ipaserver.plugins.pkinit
ipa         : DEBUG    ipaserver.plugins.pkinit is not a valid plugin module
ipa         : DEBUG    importing plugin module ipaserver.plugins.privilege
ipa         : DEBUG    importing plugin module ipaserver.plugins.pwpolicy
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=klist -V
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=Kerberos 5 version 1.14.1

ipa         : DEBUG    stderr=
ipa         : DEBUG    importing plugin module ipaserver.plugins.rabase
ipa         : DEBUG    ipaserver.plugins.rabase is not a valid plugin module
ipa         : DEBUG    importing plugin module ipaserver.plugins.radiusproxy
ipa         : DEBUG    importing plugin module ipaserver.plugins.realmdomains
ipa         : DEBUG    importing plugin module ipaserver.plugins.role
ipa         : DEBUG    importing plugin module ipaserver.plugins.schema
ipa         : DEBUG    importing plugin module ipaserver.plugins.selfservice
ipa         : DEBUG    importing plugin module ipaserver.plugins.selinuxusermap
ipa         : DEBUG    importing plugin module ipaserver.plugins.server
ipa         : DEBUG    importing plugin module ipaserver.plugins.serverrole
ipa         : DEBUG    importing plugin module ipaserver.plugins.serverroles
ipa         : DEBUG    importing plugin module ipaserver.plugins.service
ipa         : DEBUG    importing plugin module ipaserver.plugins.servicedelegation
ipa         : DEBUG    importing plugin module ipaserver.plugins.session
ipa         : DEBUG    importing plugin module ipaserver.plugins.stageuser
ipa         : DEBUG    importing plugin module ipaserver.plugins.sudo
ipa         : DEBUG    ipaserver.plugins.sudo is not a valid plugin module
ipa         : DEBUG    importing plugin module ipaserver.plugins.sudocmd
ipa         : DEBUG    importing plugin module ipaserver.plugins.sudocmdgroup
ipa         : DEBUG    importing plugin module ipaserver.plugins.sudorule
ipa         : DEBUG    importing plugin module ipaserver.plugins.topology
ipa         : DEBUG    importing plugin module ipaserver.plugins.trust
ipa         : DEBUG    importing plugin module ipaserver.plugins.user
ipa         : DEBUG    importing plugin module ipaserver.plugins.vault
ipa         : DEBUG    importing plugin module ipaserver.plugins.virtual
ipa         : DEBUG    ipaserver.plugins.virtual is not a valid plugin module
ipa         : DEBUG    importing plugin module ipaserver.plugins.xmlserver
ipa.ipapython.ipaldap.SchemaCache: DEBUG    flushing ldapi://%2fvar%2frun%2fslapd-OFFICE-FR-LYRA.socket from SchemaCache
ipa.ipapython.ipaldap.SchemaCache: DEBUG    retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-OFFICE-FR-LYRA.socket conn=<ldap.ldapobject.SimpleLDAPObject instancat 0x4df0a70>
ipa         : DEBUG    KRB5CCNAME set to None
ipa         : DEBUG    Failed to find default ccache: Major (851968): Unspecified GSS failure.  Minor code may provide more information, Minor (2529639053): No Kerberos credentialavailable (default cache: KEYRING:persistent:0)
Password for admin.LYRA:
ipa         : DEBUG    Initializing principal admin.LYRA using password
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/usr/bin/kinit admin.LYRA -c /tmp/tmpbEjRX4
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=Password for admin.LYRA:

ipa         : DEBUG    stderr=
Directory Manager (existing master) password:

ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/usr/bin/gpg-agent --batch --homedir /tmp/tmpxe8HYDipa/ipa-Hruo9a/.gnupg --daemon /usr/bin/gpg --batch --homedir /tmp/tmpxe8HYDipa/ipa-Hruo9a/.gnupg --ssphrase-fd 0 --yes --no-tty -o /tmp/tmpxe8HYDipa/files.tar -d /var/lib/ipa/replica-info-ds02.lbg.office.fr.lyra.gpg
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=tar xf /tmp/tmpxe8HYDipa/files.tar -C /tmp/tmpxe8HYDipa
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=
ipa         : DEBUG    stderr=
ipa         : DEBUG    Installing replica file with version 40400 (0 means no version in prepared file).
ipa         : DEBUG    Check if ds02.lbg.office.fr.lyra is a primary hostname for localhost
ipa         : DEBUG    Primary hostname for localhost: ds02.lbg.office.fr.lyra
ipa         : DEBUG    Search DNS for ds02.lbg.office.fr.lyra
ipa         : DEBUG    Check if ds02.lbg.office.fr.lyra is not a CNAME
ipa         : DEBUG    Check reverse address of 10.33.112.5
ipa         : DEBUG    Found reverse name: ds02.lbg.office.fr.lyra
ipa.ipaserver.plugins.ldap2.ldap2: DEBUG    Created connection context.ldap2_51165200
Run connection check to master
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/usr/sbin/ipa-replica-conncheck --master ds01.lbg.office.fr.lyra --auto-master-check --realm OFFICE.FR.LYRA --hostname ds02.lbg.office.fr.lyra --passwo XXXXXXXX --ca-cert-file /tmp/tmpxe8HYDipa/realm_info/ca.crt
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=Check connection from replica to remote master 'ds01.lbg.office.fr.lyra':
   Directory Service: Unsecure port (389): OK
   Directory Service: Secure port (636): OK
   Kerberos KDC: TCP (88): OK
   Kerberos Kpasswd: TCP (464): OK
   HTTP Server: Unsecure port (80): OK
   HTTP Server: Secure port (443): OK

The following list of ports use UDP protocol and would need to be
checked manually:
   Kerberos KDC: UDP (88): SKIPPED
   Kerberos Kpasswd: UDP (464): SKIPPED

Connection from replica to master is OK.
Start listening on required ports for remote master check
Get credentials to log in to remote master
Check RPC connection to remote master
Execute check on remote master
Check connection from master to remote replica 'ds02.lbg.office.fr.lyra':
   Directory Service: Unsecure port (389): OK
   Directory Service: Secure port (636): OK
   Kerberos KDC: TCP (88): OK
   Kerberos KDC: UDP (88): WARNING
   Kerberos Kpasswd: TCP (464): OK
   Kerberos Kpasswd: UDP (464): WARNING
   HTTP Server: Unsecure port (80): OK
   HTTP Server: Secure port (443): OK
The following UDP ports could not be verified as open: 88, 464
This can happen if they are already bound to an application
and ipa-replica-conncheck cannot attach own UDP responder.

Connection from master to replica is OK.

ipa         : DEBUG    stderr=
Connection check OK
ipa         : DEBUG    Installing CA Replica from master with a merged database
ipa.ipaserver.plugins.ldap2.ldap2: DEBUG    Destroyed connection context.ldap2_51165200
ipa         : DEBUG    Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
ipa         : DEBUG    Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes 30 seconds
Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes 30 seconds
ipa         : DEBUG      [1/25]: creating certificate server user
  [1/25]: creating certificate server user
ipa.ipaplatform.base.tasks: DEBUG    group pkiuser exists
ipa.ipaplatform.base.tasks: DEBUG    user pkiuser exists
ipa         : DEBUG      duration: 0 seconds
ipa         : DEBUG      [2/25]: configuring certificate server instance
  [2/25]: configuring certificate server instance
ipa         : DEBUG    Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
ipa         : DEBUG    Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
ipa.ipaserver.install.cainstance.CAInstance: DEBUG    Contents of pkispawn configuration file (/tmp/tmp6fr7Dt):
[CA]
pki_security_domain_name = IPA
pki_enable_proxy = True
pki_restart_configured_instance = False
pki_backup_keys = True
pki_backup_password = XXXXXXXX
pki_profiles_in_ldap = True
pki_default_ocsp_uri = http://ipa-ca.office.fr.lyra/ca/ocsp
pki_client_database_dir = /tmp/tmp-80SlNL
pki_client_database_password = XXXXXXXX
pki_client_database_purge = False
pki_client_pkcs12_password = XXXXXXXX
pki_admin_name = admin
pki_admin_uid = admin
pki_admin_email = root@localhost
pki_admin_password = XXXXXXXX
pki_admin_nickname = ipa-ca-agent
pki_admin_subject_dn = cn=ipa-ca-agent,O=OFFICE.FR.LYRA
pki_client_admin_cert_p12 = /root/ca-agent.p12
pki_ds_ldap_port = 389
pki_ds_password = XXXXXXXX
pki_ds_base_dn = o=ipaca
pki_ds_database = ipaca
pki_subsystem_subject_dn = cn=CA Subsystem,O=OFFICE.FR.LYRA
pki_ocsp_signing_subject_dn = cn=OCSP Subsystem,O=OFFICE.FR.LYRA
pki_ssl_server_subject_dn = cn=ds02.lbg.office.fr.lyra,O=OFFICE.FR.LYRA
pki_audit_signing_subject_dn = cn=CA Audit,O=OFFICE.FR.LYRA
pki_ca_signing_subject_dn = cn=Certificate Authority,O=OFFICE.FR.LYRA
pki_subsystem_nickname = subsystemCert cert-pki-ca
pki_ocsp_signing_nickname = ocspSigningCert cert-pki-ca
pki_ssl_server_nickname = Server-Cert cert-pki-ca
pki_audit_signing_nickname = auditSigningCert cert-pki-ca
pki_ca_signing_nickname = caSigningCert cert-pki-ca
pki_ca_signing_key_algorithm = SHA256withRSA
pki_security_domain_hostname = ds01.lbg.office.fr.lyra
pki_security_domain_https_port = 443
pki_security_domain_user = admin
pki_security_domain_password = XXXXXXXX
pki_clone = True
pki_clone_pkcs12_path = /tmp/ca.p12
pki_clone_pkcs12_password = XXXXXXXX
pki_clone_replication_security = TLS
pki_clone_replication_master_port = 389
pki_clone_replication_clone_port = 389
pki_clone_replicate_schema = False
pki_clone_uri = https://ds01.lbg.office.fr.lyra:443


ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/usr/sbin/pkispawn -s CA -f /tmp/tmp6fr7Dt

ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=Log file: /var/log/pki/pki-ca-spawn.20170323171403.log
Loading deployment configuration from /tmp/tmp6fr7Dt.
Installing CA into /var/lib/pki/pki-tomcat.
Storing deployment configuration into /etc/sysconfig/pki/tomcat/pki-tomcat/ca/deployment.cfg.
Importing certificates from /tmp/ca.p12:
---------------
5 entries found
---------------
  Certificate ID: d4822cf493174cb3e82d3add4056c01d19d3608f
  Serial Number: 0x2
  Nickname: ocspSigningCert cert-pki-ca
  Subject DN: CN=OCSP Subsystem,O=OFFICE.FR.LYRA
  Issuer DN: CN=Certificate Authority,O=OFFICE.FR.LYRA
  Trust Flags: u,u,u
  Has Key: true

  Certificate ID: 55f8f567613c5f19b3ccd8152a61a2428e52d493
  Serial Number: 0x1
  Nickname: caSigningCert cert-pki-ca
  Subject DN: CN=Certificate Authority,O=OFFICE.FR.LYRA
  Issuer DN: CN=Certificate Authority,O=OFFICE.FR.LYRA
  Trust Flags: CTu,Cu,Cu
  Has Key: true

  Certificate ID: ba4cbe861fa8699621989bb3b97ec66494ae9828
  Serial Number: 0x4
  Nickname: subsystemCert cert-pki-ca
  Subject DN: CN=CA Subsystem,O=OFFICE.FR.LYRA
  Issuer DN: CN=Certificate Authority,O=OFFICE.FR.LYRA
  Trust Flags: u,u,u
  Has Key: true

  Certificate ID: dbb94cb0b2a5671852095b540f9f8da589de5204
  Serial Number: 0x3
  Nickname: Server-Cert cert-pki-ca
  Subject DN: CN=ds01.lbg.office.fr.lyra,O=OFFICE.FR.LYRA
  Issuer DN: CN=Certificate Authority,O=OFFICE.FR.LYRA
  Trust Flags: u,u,u
  Has Key: true

  Certificate ID: 3ce3dfacb091b563cf2e4e53e2c19bfe3b60ad49
  Serial Number: 0x5
  Nickname: auditSigningCert cert-pki-ca
  Subject DN: CN=CA Audit,O=OFFICE.FR.LYRA
  Issuer DN: CN=Certificate Authority,O=OFFICE.FR.LYRA
  Trust Flags: u,u,Pu
  Has Key: true
---------------
Import complete
---------------
Imported certificates in /etc/pki/pki-tomcat/alias:

Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI

ocspSigningCert cert-pki-ca                                  u,u,u
subsystemCert cert-pki-ca                                    u,u,u
caSigningCert cert-pki-ca                                    CTu,Cu,Cu
Server-Cert cert-pki-ca                                      u,u,u
auditSigningCert cert-pki-ca                                 u,u,Pu

    ==========================================================================
                                INSTALLATION SUMMARY
    ==========================================================================

      Administrator's username:             admin

      This CA subsystem of the 'pki-tomcat' instance
      is a clone.

      To check the status of the subsystem:
            systemctl status pki-tomcatd

      To restart the subsystem:
            systemctl restart pki-tomcatd

      The URL for the subsystem is:
            https://ds02.lbg.office.fr.lyra:8443/ca

      PKI instances will be enabled upon system boot

    ==========================================================================


ipa         : DEBUG    stderr=Created symlink from /etc/systemd/system/multi-user.target.wants/pki-tomcatd.target to /usr/lib/systemd/system/pki-tomcatd.target.

ipa.ipaserver.install.cainstance.CAInstance: DEBUG    completed creating ca instance
ipa         : DEBUG      duration: 228 seconds
ipa         : DEBUG      [3/25]: stopping certificate server instance to update CS.cfg
  [3/25]: stopping certificate server instance to update CS.cfg
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/bin/systemctl stop pki-tomcatd
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=
ipa         : DEBUG    stderr=
ipa         : DEBUG      duration: 11 seconds
ipa         : DEBUG      [4/25]: backing up CS.cfg
  [4/25]: backing up CS.cfg
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/bin/systemctl is-active pki-tomcatd
ipa         : DEBUG    Process finished, return code=3
ipa         : DEBUG    stdout=inactive

ipa         : DEBUG    stderr=
ipa         : DEBUG      duration: 0 seconds
ipa         : DEBUG      [5/25]: disabling nonces
  [5/25]: disabling nonces
ipa         : DEBUG      duration: 0 seconds
ipa         : DEBUG      [6/25]: set up CRL publishing
  [6/25]: set up CRL publishing
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/usr/sbin/selinuxenabled
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=
ipa         : DEBUG    stderr=
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/sbin/restorecon /var/lib/ipa/pki-ca/publish
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=
ipa         : DEBUG    stderr=
ipa         : DEBUG      duration: 0 seconds
ipa         : DEBUG      [7/25]: enable PKIX certificate path discovery and validation
  [7/25]: enable PKIX certificate path discovery and validation
ipa         : DEBUG      duration: 0 seconds
ipa         : DEBUG      [8/25]: starting certificate server instance
  [8/25]: starting certificate server instance
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/bin/systemctl start pki-tomcatd
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=
ipa         : DEBUG    stderr=
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/bin/systemctl is-active pki-tomcatd
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=active

ipa         : DEBUG    stderr=
ipa         : DEBUG    wait_for_open_ports: localhost [8080, 8443] timeout 300
ipa         : DEBUG    Waiting until the CA is running
ipa         : DEBUG    request POST http://ds01.lbg.office.fr.lyra:8080/ca/admin/ca/getStatus
ipa         : DEBUG    request body ''
ipa         : DEBUG    response status 200
ipa         : DEBUG    response headers {'date': 'Thu, 23 Mar 2017 16:18:11 GMT', 'content-length': '170', 'content-type': 'application/xml', 'server': 'Apache-Coyote/1.1'}
ipa         : DEBUG    response body '<?xml version="1.0" encoding="UTF-8" standalone="no"?><XMLResponse><State>1</State><Type>CA</Type><Status>running</Status><Version>10.3.3-17._3</Version></XMLResponse>'
ipa         : DEBUG    The CA status is: running
ipa         : DEBUG      duration: 11 seconds
ipa         : DEBUG      [9/25]: importing CA chain to RA certificate database
  [9/25]: importing CA chain to RA certificate database
ipa         : DEBUG    Loading Index file from '/var/lib/ipa/sysrestore/sysrestore.index'
ipa         : DEBUG    Starting external process
ipa         : DEBUG    args=/usr/bin/certutil -d /etc/httpd/alias -L
ipa         : DEBUG    Process finished, return code=0
ipa         : DEBUG    stdout=
Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI

Server-Cert                                                  u,u,u
OFFICE.FR.LYRA IPA CA                                        CT,C,C
ipaCert                                                      u,u,u

ipa         : DEBUG    stderr=
^Cipa         : DEBUG    Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 449, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 439, in run_step
    method()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 835, in __import_ca_chain
    chain = self.__get_ca_chain()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 826, in __get_ca_chain
    return dogtag.get_ca_certchain(ca_host=self.fqdn)
  File "/usr/lib/python2.7/site-packages/ipapython/dogtag.py", line 73, in get_ca_certchain
    res = conn.getresponse()
  File "/usr/lib64/python2.7/httplib.py", line 1089, in getresponse
    response.begin()
  File "/usr/lib64/python2.7/httplib.py", line 444, in begin
    version, status, reason = self._read_status()
  File "/usr/lib64/python2.7/httplib.py", line 400, in _read_status
    line = self.fp.readline(_MAXLINE + 1)
  File "/usr/lib64/python2.7/socket.py", line 476, in readline
    data = self._sock.recv(self._rbufsize)
KeyboardInterrupt

ipa         : DEBUG      [error] KeyboardInterrupt:
  [error] KeyboardInterrupt:
ipa         : DEBUG      File "/usr/lib/python2.7/site-packages/ipaserver/install/installutils.py", line 752, in run_script
    return_value = main_function()

  File "/usr/sbin/ipa-ca-install", line 302, in main
    install(safe_options, options, filename)

  File "/usr/sbin/ipa-ca-install", line 242, in install
    install_replica(safe_options, options, filename)

  File "/usr/sbin/ipa-ca-install", line 204, in install_replica
    ca.install(True, config, options)

  File "/usr/lib/python2.7/site-packages/ipaserver/install/ca.py", line 118, in install
    install_step_0(standalone, replica_config, options)

  File "/usr/lib/python2.7/site-packages/ipaserver/install/ca.py", line 140, in install_step_0
    ra_p12=getattr(options, 'ra_p12', None))

  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 1558, in install_replica_ca
    subject_base=config.subject_base)

  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 437, in configure_instance
    self.start_creation(runtime=210)

  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 449, in start_creation
    run_step(full_msg, method)

  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 439, in run_step
    method()

  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 835, in __import_ca_chain
    chain = self.__get_ca_chain()

  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 826, in __get_ca_chain
    return dogtag.get_ca_certchain(ca_host=self.fqdn)

  File "/usr/lib/python2.7/site-packages/ipapython/dogtag.py", line 73, in get_ca_certchain
    res = conn.getresponse()

  File "/usr/lib64/python2.7/httplib.py", line 1089, in getresponse
    response.begin()

  File "/usr/lib64/python2.7/httplib.py", line 444, in begin
    version, status, reason = self._read_status()

  File "/usr/lib64/python2.7/httplib.py", line 400, in _read_status
    line = self.fp.readline(_MAXLINE + 1)

  File "/usr/lib64/python2.7/socket.py", line 476, in readline
    data = self._sock.recv(self._rbufsize)

ipa         : DEBUG    The ipa-ca-install command failed, exception: KeyboardInterrupt:

Your system may be partly configured.
Run /usr/sbin/ipa-server-install --uninstall to clean up.
Comment 7 sebastien.ducloux 2017-03-27 07:57:29 UTC 
Any clue of what's going on ?

I can do other tests or post other logs if necessary.
Comment 8 sebastien.ducloux 2017-03-28 14:21:31 UTC 
Created attachment 1266992 [details]
journalctl -u pki-tomcatd --no-pager on replica

On journalctl output we can see that nothing appends after "CMSEngine: init(): password test execution failed for replicationdbwith NO_SUCH_USER."

In normal output I can see the next step is the creation of http-bio-8080 and http-bio-8443, then "CA is started".

What is the process exactly waiting for ?

Output of "netstat -naple | egrep "8080|8443":
tcp6       1      0 :::8080                 :::*                    LISTEN      17         10984668   7573/java
tcp6       0      0 :::8443                 :::*                    LISTEN      17         10984704   7573/java

So the bind opration seems to be successfull. If not why no error log ?
Comment 9 Martin Bašti 2017-04-03 08:41:11 UTC 
This looks related to https://pagure.io/freeipa/issue/6766

IMO it is the same case, dogtag started successfully, it is listening on port but for unknown reason it didn't sent any data to opened connection, so IPA stucks forever (or waiting for TCP timeout what can be several minutes).
Comment 10 sebastien.ducloux 2017-04-03 09:07:46 UTC 
(In reply to Martin Bašti from comment #9)
> This looks related to https://pagure.io/freeipa/issue/6766
> 
> IMO it is the same case, dogtag started successfully, it is listening on
> port but for unknown reason it didn't sent any data to opened connection, so
> IPA stucks forever (or waiting for TCP timeout what can be several minutes).

Yes it seems to be focused onthe no timeout detection of the http lib during installation process.

But the root problem is : why does dogtag dameon not initialize itself correctly to be able to answer HTTP requests ? And why no error logs are written if problem occurs ?
Comment 11 Petr Vobornik 2017-04-06 16:09:40 UTC 
Moving to dogtag component because of comment 9 and comment 10.
Comment 12 Matthew Harmsen 2017-04-06 21:54:16 UTC 
Upstream ticket:
https://pagure.io/dogtagpki/issue/2632
Comment 13 Matthew Harmsen 2017-04-06 21:56:14 UTC 
Per PKI Bug Council of 04/05/2017:   7.4 - critical
Comment 14 Matthew Harmsen 2017-04-19 16:51:54 UTC 
Potential cause of issue:
* https://pagure.io/freeipa/issue/6766 - Getting dogtag status stuck
* https://pagure.io/389-ds-base/issue/49209 - Hang due to omitted replica lock release
Comment 17 German Parente 2017-04-25 16:16:38 UTC 
imho, the way to confirm it's a duplicate would be taking a pstack of ns-slapd process and match it to the one in

 https://bugzilla.redhat.com/show_bug.cgi?id=1432016 
 Possible deadlock while installing an ipa replica.
Comment 18 Matthew Harmsen 2017-05-01 19:02:43 UTC 
Moving back to ipa for "duplicate" testing due to comments #14-#17
Comment 20 Petr Vobornik 2017-05-02 07:27:23 UTC 
To know that it is really a duplicate, we would need the information from the environment where it was created. Making comment 17 public, which points to bug 1432016 which has the pstack which needs to be compared.
Comment 21 sebastien.ducloux 2017-05-02 09:16:09 UTC 
This is dirsrv pstack in my case :

Thread 49 (Thread 0x7ff8c7f6e700 (LWP 30715)):
#0  0x00007ff8dac7dba3 in select () from /lib64/libc.so.6
#1  0x00007ff8dd4200d9 in DS_Sleep () from /usr/lib64/dirsrv/libslapd.so.0
#2  0x00007ff8cf934797 in deadlock_threadmain () from /usr/lib64/dirsrv/plugins/libback-ldbm.so
#3  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#4  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#5  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 48 (Thread 0x7ff8c776d700 (LWP 30716)):
#0  0x00007ff8dac7dba3 in select () from /lib64/libc.so.6
#1  0x00007ff8dd4200d9 in DS_Sleep () from /usr/lib64/dirsrv/libslapd.so.0
#2  0x00007ff8cf938916 in checkpoint_threadmain () from /usr/lib64/dirsrv/plugins/libback-ldbm.so
#3  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#4  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#5  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 47 (Thread 0x7ff8c6f6c700 (LWP 30717)):
#0  0x00007ff8dac7dba3 in select () from /lib64/libc.so.6
#1  0x00007ff8dd4200d9 in DS_Sleep () from /usr/lib64/dirsrv/libslapd.so.0
#2  0x00007ff8cf934a0f in trickle_threadmain () from /usr/lib64/dirsrv/plugins/libback-ldbm.so
#3  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#4  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#5  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 46 (Thread 0x7ff8c676b700 (LWP 30718)):
#0  0x00007ff8dac7dba3 in select () from /lib64/libc.so.6
#1  0x00007ff8dd4200d9 in DS_Sleep () from /usr/lib64/dirsrv/libslapd.so.0
#2  0x00007ff8cf92f687 in perf_threadmain () from /usr/lib64/dirsrv/plugins/libback-ldbm.so
#3  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#4  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#5  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 45 (Thread 0x7ff8c5d61700 (LWP 30719)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd40cfb8 in slapi_wait_condvar () from /usr/lib64/dirsrv/libslapd.so.0
#3  0x00007ff8d287d7ee in cos_cache_wait_on_change () from /usr/lib64/dirsrv/plugins/libcos-plugin.so
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 44 (Thread 0x7ff8dd7d9700 (LWP 30720)):
#0  0x00007ff8daf5ba82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b1c97 in pt_TimedWait () from /lib64/libnspr4.so
#2  0x00007ff8db5b217e in PR_WaitCondVar () from /lib64/libnspr4.so
#3  0x00007ff8cf68d114 in _cl5TrimMain () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 43 (Thread 0x7ff8b63c1700 (LWP 30726)):
#0  0x00007ff8daf5ba82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b1c97 in pt_TimedWait () from /lib64/libnspr4.so
#2  0x00007ff8db5b217e in PR_WaitCondVar () from /lib64/libnspr4.so
#3  0x00007ff8dd8caa13 in housecleaning ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 42 (Thread 0x7ff8b5bc0700 (LWP 30727)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2473 in PR_EnterMonitor () from /lib64/libnspr4.so
#2  0x00007ff8cf6b2e58 in replica_update_state () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#3  0x00007ff8dd3afe9a in eq_loop () from /usr/lib64/dirsrv/libslapd.so.0
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 41 (Thread 0x7ff8b48ed700 (LWP 30730)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 40 (Thread 0x7ff8abfff700 (LWP 30731)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 39 (Thread 0x7ff8ab7fe700 (LWP 30732)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 38 (Thread 0x7ff8aaffd700 (LWP 30733)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 37 (Thread 0x7ff8aa7fc700 (LWP 30734)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 36 (Thread 0x7ff8a9ffb700 (LWP 30735)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 35 (Thread 0x7ff8a97fa700 (LWP 30736)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 34 (Thread 0x7ff8a8ff9700 (LWP 30737)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 33 (Thread 0x7ff8a3fff700 (LWP 30738)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 32 (Thread 0x7ff8a37fe700 (LWP 30739)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 31 (Thread 0x7ff8a2ffd700 (LWP 30740)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2473 in PR_EnterMonitor () from /lib64/libnspr4.so
#2  0x00007ff8cf6b0321 in replica_get_generation () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#3  0x00007ff8cf6a9b90 in copy_operation_parameters () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#4  0x00007ff8cf6aacf2 in multimaster_preop_add () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#5  0x00007ff8dd3e9db8 in plugin_call_func () from /usr/lib64/dirsrv/libslapd.so.0
#6  0x00007ff8dd3ea043 in plugin_call_plugins () from /usr/lib64/dirsrv/libslapd.so.0
#7  0x00007ff8dd38de79 in op_shared_add () from /usr/lib64/dirsrv/libslapd.so.0
#8  0x00007ff8dd38f1e0 in do_add () from /usr/lib64/dirsrv/libslapd.so.0
#9  0x00007ff8dd8c19b3 in connection_threadmain ()
#10 0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#11 0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#12 0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 30 (Thread 0x7ff8a27fc700 (LWP 30741)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 29 (Thread 0x7ff8a1ffb700 (LWP 30742)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 28 (Thread 0x7ff8a17fa700 (LWP 30743)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 27 (Thread 0x7ff8a0ff9700 (LWP 30744)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 26 (Thread 0x7ff8a07f8700 (LWP 30745)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 25 (Thread 0x7ff89fff7700 (LWP 30746)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 24 (Thread 0x7ff89f7f6700 (LWP 30747)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 23 (Thread 0x7ff89eff5700 (LWP 30748)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2473 in PR_EnterMonitor () from /lib64/libnspr4.so
#2  0x00007ff8cf6b0321 in replica_get_generation () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#3  0x00007ff8cf685d26 in _cl5GetDBFile () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#4  0x00007ff8cf688af9 in cl5GetOperationCount () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#5  0x00007ff8cf6b49a9 in replica_config_search () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#6  0x00007ff8dd3a2429 in dse_call_callback.isra.1 () from /usr/lib64/dirsrv/libslapd.so.0
#7  0x00007ff8dd3a4007 in dse_search () from /usr/lib64/dirsrv/libslapd.so.0
#8  0x00007ff8dd3de346 in op_shared_search () from /usr/lib64/dirsrv/libslapd.so.0
#9  0x00007ff8dd8d411e in do_search ()
#10 0x00007ff8dd8c1c17 in connection_threadmain ()
#11 0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#12 0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#13 0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 22 (Thread 0x7ff89e7f4700 (LWP 30749)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 21 (Thread 0x7ff89dff3700 (LWP 30750)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 20 (Thread 0x7ff89d7f2700 (LWP 30751)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 19 (Thread 0x7ff89cff1700 (LWP 30752)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 18 (Thread 0x7ff89c7f0700 (LWP 30753)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 17 (Thread 0x7ff89bfef700 (LWP 30754)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 16 (Thread 0x7ff89b7ee700 (LWP 30755)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 15 (Thread 0x7ff89afed700 (LWP 30756)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 14 (Thread 0x7ff89a7ec700 (LWP 30757)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 13 (Thread 0x7ff899feb700 (LWP 30758)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 12 (Thread 0x7ff8997ea700 (LWP 30759)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8bf65e in connection_wait_for_new_work ()
#3  0x00007ff8dd8c0d89 in connection_threadmain ()
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 11 (Thread 0x7ff898fe9700 (LWP 30760)):
#0  0x00007ff8dac7dba3 in select () from /lib64/libc.so.6
#1  0x00007ff8dd4200d9 in DS_Sleep () from /usr/lib64/dirsrv/libslapd.so.0
#2  0x00007ff8dd8c29d5 in time_thread ()
#3  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#4  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#5  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 10 (Thread 0x7ff8927fd700 (LWP 30800)):
#0  0x00007ff8daf5ba82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b1c97 in pt_TimedWait () from /lib64/libnspr4.so
#2  0x00007ff8db5b217e in PR_WaitCondVar () from /lib64/libnspr4.so
#3  0x00007ff8d267241c in sync_send_results () from /usr/lib64/dirsrv/plugins/libcontentsync-plugin.so
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 9 (Thread 0x7ff8797da700 (LWP 29752)):
#0  0x00007ff8daf5ba82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b1c97 in pt_TimedWait () from /lib64/libnspr4.so
#2  0x00007ff8db5b217e in PR_WaitCondVar () from /lib64/libnspr4.so
#3  0x00007ff8cf6a43a4 in protocol_sleep () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#4  0x00007ff8cf6a7add in repl5_inc_run () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#5  0x00007ff8cf6abd3c in prot_thread_main () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#6  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#7  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#8  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 8 (Thread 0x7ff8937fe700 (LWP 5363)):
#0  0x00007ff8daf5ba82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b1c97 in pt_TimedWait () from /lib64/libnspr4.so
#2  0x00007ff8db5b217e in PR_WaitCondVar () from /lib64/libnspr4.so
#3  0x00007ff8d267241c in sync_send_results () from /usr/lib64/dirsrv/plugins/libcontentsync-plugin.so
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 7 (Thread 0x7ff8b77fe700 (LWP 28488)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd40cfb8 in slapi_wait_condvar () from /usr/lib64/dirsrv/libslapd.so.0
#3  0x00007ff8cddc8efd in roles_cache_wait_on_change () from /usr/lib64/dirsrv/plugins/libroles-plugin.so
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 6 (Thread 0x7ff87c7e0700 (LWP 28489)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd40cfb8 in slapi_wait_condvar () from /usr/lib64/dirsrv/libslapd.so.0
#3  0x00007ff8cddc8efd in roles_cache_wait_on_change () from /usr/lib64/dirsrv/plugins/libroles-plugin.so
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 5 (Thread 0x7ff8b7fff700 (LWP 28542)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd40cfb8 in slapi_wait_condvar () from /usr/lib64/dirsrv/libslapd.so.0
#3  0x00007ff8cddc8efd in roles_cache_wait_on_change () from /usr/lib64/dirsrv/plugins/libroles-plugin.so
#4  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 4 (Thread 0x7ff881feb700 (LWP 28543)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2473 in PR_EnterMonitor () from /lib64/libnspr4.so
#2  0x00007ff8cf6af405 in replica_get_ruv () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#3  0x00007ff8cf6ac900 in acquire_replica () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#4  0x00007ff8cf6a5c66 in repl5_inc_run () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#5  0x00007ff8cf6abd3c in prot_thread_main () from /usr/lib64/dirsrv/plugins/libreplication-plugin.so
#6  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#7  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#8  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 3 (Thread 0x7ff8b6ffd700 (LWP 28832)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8cec35 in ps_send_results ()
#3  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#4  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#5  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 2 (Thread 0x7ff893fff700 (LWP 28838)):
#0  0x00007ff8daf5b6d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff8db5b2200 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x00007ff8dd8cec35 in ps_send_results ()
#3  0x00007ff8db5b79bb in _pt_root () from /lib64/libnspr4.so
#4  0x00007ff8daf57dc5 in start_thread () from /lib64/libpthread.so.0
#5  0x00007ff8dac8673d in clone () from /lib64/libc.so.6
Thread 1 (Thread 0x7ff8dd85b880 (LWP 30713)):
#0  0x00007ff8dac7bdfd in poll () from /lib64/libc.so.6
#1  0x00007ff8db5b3b37 in _pr_poll_with_poll () from /lib64/libnspr4.so
#2  0x00007ff8dd8c6789 in slapd_daemon ()
#3  0x00007ff8dd8b8253 in main ()
Comment 22 Petr Vobornik 2017-05-02 10:51:32 UTC 
Ludwig, by the stack in previous comment is this the same bug as bug 1432016 ?
Comment 23 Ludwig 2017-05-02 11:15:50 UTC 
yes, looks like. Severak threads waiting for the replica lock and no thread holding it
Comment 24 Petr Vobornik 2017-05-02 14:55:40 UTC 

*** This bug has been marked as a duplicate of bug 1432016 ***