[Freeipa-users] ipa-replica-install: Certificate operation cannot be completed: Unable to communicate with CMS (503)

Tue Feb 14 13:32:03 UTC 2017

Hi all,

I'm trying to setup a freeipa masterserver and a replica, on a fresh
install of CentOS 7.3

after running ipa-server-install on the master and running
ipa-client-install on the replica the ipa-replica-install command fails
to restart the directory server.

Turns out this is because the DS Certificate was never received. It
fails with status: CA_UNREACHABLE and I can't figure out why this is
failing.

Could someone give me some pointers?

on the replica:

/var/log/ipareplica-install.log
2017-02-14T12:21:20Z DEBUG certmonger request is in state
dbus.String(u'NEWLY_ADDED_READING_KEYINFO', variant_level=1)
2017-02-14T12:21:25Z DEBUG certmonger request is in state
dbus.String(u'CA_UNREACHABLE', variant_level=1)
2017-02-14T12:21:25Z DEBUG flushing
ldapi://%2fvar%2frun%2fslapd-MY-REALM.socket from SchemaCache
2017-02-14T12:21:25Z DEBUG retrieving schema for SchemaCache
url=ldapi://%2fvar%2frun%2fslapd-MY-REALM.socket
conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x73101b8>
2017-02-14T12:21:25Z DEBUG   duration: 5 seconds
2017-02-14T12:21:25Z DEBUG   [28/44]: restarting directory server

<fails>

# getcert list
Number of certificates and requests being tracked: 1.
Request ID '20170214122119':
    status: CA_UNREACHABLE
    ca-error: Server at https://<ipa-server>/ipa/xml failed request,
will retry: 4301 (RPC failed at server.  Certificate operation cannot be
completed: Unable to communicate with CMS (503)).
    stuck: no
    key pair storage:
type=NSSDB,location='/etc/dirsrv/slapd-MY_REALM',nickname='Server-Cert',token='NSS
Certificate DB',pinfile='/etc/dirsrv/slapd-MY_REALM//pwdfile.txt'
    certificate:
type=NSSDB,location='/etc/dirsrv/slapd-MY_REALM',nickname='Server-Cert'
    CA: IPA
    issuer:
    subject:
    expires: unknown
    pre-save command:
    post-save command:
    track: yes
    auto-renew: yes

# certutil -L -d /etc/dirsrv/slapd-MY_REALM/

Certificate Nickname                                         Trust
Attributes

SSL,S/MIME,JAR/XPI

MY_REALM IPA CA                                          CT,C,C

# certutil -L -d /etc/httpd/alias/

Certificate Nickname                                         Trust
Attributes

SSL,S/MIME,JAR/XPI

cacert                                                       CTu,Cu,Cu
beta                                                         u,pu,u
alpha                                                        u,pu,u
Server-Cert                                                  u,u,u

# curl --negotiate -u : https://ipa-server/ipa/xml --referer
https://ipa-server/ipa/xml -I
HTTP/1.1 401 Unauthorized
Date: Tue, 14 Feb 2017 12:07:02 GMT
Server: Apache/2.4.6 (CentOS) mod_auth_gssapi/1.4.0 mod_nss/1.0.14
NSS/3.21 Basic ECC mod_wsgi/3.4 Python/2.7.5
WWW-Authenticate: Negotiate
X-Frame-Options: DENY
Content-Security-Policy: frame-ancestors 'none'
Last-Modified: Tue, 17 Jan 2017 17:34:23 GMT
Accept-Ranges: bytes
Content-Length: 1474
Content-Type: text/html; charset=UTF-8

HTTP/1.1 200 Success
Date: Tue, 14 Feb 2017 12:07:02 GMT
Server: Apache/2.4.6 (CentOS) mod_auth_gssapi/1.4.0 mod_nss/1.0.14
NSS/3.21 Basic ECC mod_wsgi/3.4 Python/2.7.5
Set-Cookie: ipa_session=<snip>
WWW-Authenticate: Negotiate <snip>
X-Frame-Options: DENY
Content-Security-Policy: frame-ancestors 'none'
Vary: Accept-Encoding
Content-Type: text/xml; charset=utf-8

On the ipa-server:

/var/log/pki/pki-tomcat/ca/debug

[14/Feb/2017:13:20:15][Timer-0]: SessionTimer: run()
[14/Feb/2017:13:20:15][Timer-0]: LDAPSecurityDomainSessionTable:
getSessionIds()
[14/Feb/2017:13:20:15][Timer-0]: LDAPSecurityDomainSessionTable:
searching ou=sessions,ou=Security Domain,o=ipaca
[14/Feb/2017:13:20:15][Timer-0]: In LdapBoundConnFactory::getConn()
[14/Feb/2017:13:20:15][Timer-0]: masterConn is connected: true
[14/Feb/2017:13:20:15][Timer-0]: getConn: conn is connected true
[14/Feb/2017:13:20:15][Timer-0]: getConn: mNumConns now 2
[14/Feb/2017:13:20:15][Timer-0]: SecurityDomainSessionTable: No active
sessions.
[14/Feb/2017:13:20:15][Timer-0]: returnConn: mNumConns now 3
[14/Feb/2017:13:25:15][Timer-0]: SessionTimer: run()
[14/Feb/2017:13:25:15][Timer-0]: LDAPSecurityDomainSessionTable:
getSessionIds()
[14/Feb/2017:13:25:15][Timer-0]: LDAPSecurityDomainSessionTable:
searching ou=sessions,ou=Security Domain,o=ipaca
[14/Feb/2017:13:25:15][Timer-0]: In LdapBoundConnFactory::getConn()
[14/Feb/2017:13:25:15][Timer-0]: masterConn is connected: true
[14/Feb/2017:13:25:15][Timer-0]: getConn: conn is connected true
[14/Feb/2017:13:25:15][Timer-0]: getConn: mNumConns now 2
[14/Feb/2017:13:25:15][Timer-0]: SecurityDomainSessionTable: No active
sessions.
[14/Feb/2017:13:25:15][Timer-0]: returnConn: mNumConns now 3

(so nothing at 13:21:14)

==> /var/log/pki/pki-tomcat/ca/selftests.log <==
0.localhost-startStop-1 - [14/Feb/2017:10:20:14 CET] [20] [1]
SelfTestSubsystem:  loading all self test plugin logger parameters
0.localhost-startStop-1 - [14/Feb/2017:10:20:14 CET] [20] [1]
SelfTestSubsystem:  loading all self test plugin instances
0.localhost-startStop-1 - [14/Feb/2017:10:20:14 CET] [20] [1]
SelfTestSubsystem:  loading all self test plugin instance parameters
0.localhost-startStop-1 - [14/Feb/2017:10:20:14 CET] [20] [1]
SelfTestSubsystem:  loading self test plugins in on-demand order
0.localhost-startStop-1 - [14/Feb/2017:10:20:14 CET] [20] [1]
SelfTestSubsystem:  loading self test plugins in startup order
0.localhost-startStop-1 - [14/Feb/2017:10:20:14 CET] [20] [1]
SelfTestSubsystem: Self test plugins have been successfully loaded!
0.localhost-startStop-1 - [14/Feb/2017:10:20:15 CET] [20] [1]
SelfTestSubsystem: Running self test plugins specified to be executed at
startup:
0.localhost-startStop-1 - [14/Feb/2017:10:20:15 CET] [20] [1]
CAPresence:  CA is present
0.localhost-startStop-1 - [14/Feb/2017:10:20:15 CET] [20] [1]
SystemCertsVerification: system certs verification success
0.localhost-startStop-1 - [14/Feb/2017:10:20:15 CET] [20] [1]
SelfTestSubsystem: All CRITICAL self test plugins ran SUCCESSFULLY at
startup!

and /var/log/pki/pki-tomcat/localhost.2017-02-14.log is filled with
these exceptions that aren't pointing me to anywhere.

SEVERE: Servlet.service() for servlet [Resteasy] in context with path
[/ca] threw exception
org.jboss.resteasy.spi.UnhandledException:
org.jboss.resteasy.core.NoMessageBodyWriterFoundFailure: Could not find
MessageBodyWriter for response object of type:
com.netscape.certsrv.base.PKIException$Data of media type:
application/x-www-form-urlencoded
        at
org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:157)
        at
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:372)
        at
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179)
        at
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220)
        at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
        at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
        at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:288)
        at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:285)
        at java.security.AccessController.doPrivileged(Native Method)

        ...

# getcert list
Number of certificates and requests being tracked: 8.
Request ID '20170214084423':
    status: MONITORING
    stuck: no
    key pair storage:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='auditSigningCert
cert-pki-ca',token='NSS Certificate DB',pin set
    certificate:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='auditSigningCert
cert-pki-ca',token='NSS Certificate DB'
    CA: dogtag-ipa-ca-renew-agent
    issuer: CN=Certificate Authority,O=MY-REALM
    subject: CN=CA Audit,O=MY-REALM
    expires: 2019-02-04 08:42:52 UTC
    key usage: digitalSignature,nonRepudiation
    pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
    post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert
"auditSigningCert cert-pki-ca"
    track: yes
    auto-renew: yes
Request ID '20170214084425':
    status: MONITORING
    stuck: no
    key pair storage:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='ocspSigningCert
cert-pki-ca',token='NSS Certificate DB',pin set
    certificate:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='ocspSigningCert
cert-pki-ca',token='NSS Certificate DB'
    CA: dogtag-ipa-ca-renew-agent
    issuer: CN=Certificate Authority,O=MY-REALM
    subject: CN=OCSP Subsystem,O=MY-REALM
    expires: 2019-02-04 08:42:48 UTC
    key usage: digitalSignature,nonRepudiation,keyCertSign,cRLSign
    eku: id-kp-OCSPSigning
    pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
    post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert
"ocspSigningCert cert-pki-ca"
    track: yes
    auto-renew: yes
Request ID '20170214084428':
    status: MONITORING
    stuck: no
    key pair storage:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='subsystemCert
cert-pki-ca',token='NSS Certificate DB',pin set
    certificate:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='subsystemCert
cert-pki-ca',token='NSS Certificate DB'
    CA: dogtag-ipa-ca-renew-agent
    issuer: CN=Certificate Authority,O=MY-REALM
    subject: CN=CA Subsystem,O=MY-REALM
    expires: 2019-02-04 08:42:51 UTC
    key usage:
digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
    eku: id-kp-serverAuth,id-kp-clientAuth
    pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
    post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert
"subsystemCert cert-pki-ca"
    track: yes
    auto-renew: yes
Request ID '20170214084431':
    status: MONITORING
    stuck: no
    key pair storage:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='caSigningCert
cert-pki-ca',token='NSS Certificate DB',pin set
    certificate:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='caSigningCert
cert-pki-ca',token='NSS Certificate DB'
    CA: dogtag-ipa-ca-renew-agent
    issuer: CN=Certificate Authority,O=MY-REALM
    subject: CN=Certificate Authority,O=MY-REALM
    expires: 2037-02-14 08:42:43 UTC
    key usage: digitalSignature,nonRepudiation,keyCertSign,cRLSign
    pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
    post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert
"caSigningCert cert-pki-ca"
    track: yes
    auto-renew: yes
Request ID '20170214084434':
    status: MONITORING
    stuck: no
    key pair storage:
type=NSSDB,location='/etc/httpd/alias',nickname='ipaCert',token='NSS
Certificate DB',pinfile='/etc/httpd/alias/pwdfile.txt'
    certificate:
type=NSSDB,location='/etc/httpd/alias',nickname='ipaCert',token='NSS
Certificate DB'
    CA: dogtag-ipa-ca-renew-agent
    issuer: CN=Certificate Authority,O=MY-REALM
    subject: CN=IPA RA,O=MY-REALM
    expires: 2019-02-04 08:44:09 UTC
    key usage:
digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
    eku: id-kp-serverAuth,id-kp-clientAuth
    pre-save command: /usr/libexec/ipa/certmonger/renew_ra_cert_pre
    post-save command: /usr/libexec/ipa/certmonger/renew_ra_cert
    track: yes
    auto-renew: yes
Request ID '20170214084436':
    status: MONITORING
    stuck: no
    key pair storage:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='Server-Cert
cert-pki-ca',token='NSS Certificate DB',pin set
    certificate:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='Server-Cert
cert-pki-ca',token='NSS Certificate DB'
    CA: dogtag-ipa-renew-agent
    issuer: CN=Certificate Authority,O=MY-REALM
    subject: CN=ipa-server,O=MY-REALM
    expires: 2019-02-04 08:42:49 UTC
    key usage:
digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
    eku: id-kp-serverAuth
    pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
    post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert
"Server-Cert cert-pki-ca"
    track: yes
    auto-renew: yes
Request ID '20170214084646':
    status: MONITORING
    stuck: no
    key pair storage:
type=NSSDB,location='/etc/dirsrv/slapd-MY-REALM',nickname='Server-Cert',token='NSS
Certificate DB',pinfile='/etc/dirsrv/slapd-MY-REALM/pwdfile.txt'
    certificate:
type=NSSDB,location='/etc/dirsrv/slapd-MY-REALM',nickname='Server-Cert',token='NSS
Certificate DB'
    CA: IPA
    issuer: CN=Certificate Authority,O=MY-REALM
    subject: CN=ipa-server,O=MY-REALM
    expires: 2019-02-15 08:46:45 UTC
    key usage:
digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
    eku: id-kp-serverAuth,id-kp-clientAuth
    pre-save command:
    post-save command: /usr/libexec/ipa/certmonger/restart_dirsrv MY-REALM
    track: yes
    auto-renew: yes
Request ID '20170214085151':
    status: MONITORING
    stuck: no
    key pair storage:
type=NSSDB,location='/etc/httpd/alias',nickname='Server-Cert',token='NSS
Certificate DB',pinfile='/etc/httpd/alias/pwdfile.txt'
    certificate:
type=NSSDB,location='/etc/httpd/alias',nickname='Server-Cert',token='NSS
Certificate DB'
    CA: IPA
    issuer: CN=Certificate Authority,O=MY-REALM
    subject: CN=ipa-server,O=MY-REALM
    expires: 2019-02-15 08:51:50 UTC
    key usage:
digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
    eku: id-kp-serverAuth,id-kp-clientAuth
    pre-save command:
    post-save command: /usr/libexec/ipa/certmonger/restart_httpd
    track: yes
    auto-renew: yes

# systemctl status pki-tomcatd at pki-tomcat.service
● pki-tomcatd at pki-tomcat.service - PKI Tomcat Server pki-tomcat
   Loaded: loaded (/lib/systemd/system/pki-tomcatd at .service; enabled;
vendor preset: disabled)
   Active: active (running) since Tue 2017-02-14 10:19:32 CET; 3h 40min ago
 Main PID: 1300 (java)
   CGroup:
/system.slice/system-pki\x2dtomcatd.slice/pki-tomcatd at pki-tomcat.service
           └─1300 /usr/lib/jvm/jre-1.8.0-openjdk/bin/java
-DRESTEASY_LIB=/usr/share/java/resteasy-base
-Djava.library.path=/usr/lib64/nuxwdog-jni -classpath
/usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/...

Feb 14 10:19:57ipa-server server[1300]: SSLAuthenticatorWithFallback:
Creating SSL authenticator with fallback
Feb 14 10:19:57ipa-server server[1300]: SSLAuthenticatorWithFallback:
Setting container
Feb 14 10:20:07ipa-server server[1300]: SSLAuthenticatorWithFallback:
Initializing authenticators
Feb 14 10:20:07ipa-server server[1300]: SSLAuthenticatorWithFallback:
Starting authenticators
Feb 14 10:20:10ipa-server server[1300]:
CMSEngine.initializePasswordStore() begins
Feb 14 10:20:10ipa-server server[1300]:
CMSEngine.initializePasswordStore(): tag=internaldb
Feb 14 10:20:10ipa-server server[1300]:
CMSEngine.initializePasswordStore(): tag=replicationdb
Feb 14 10:20:15ipa-server server[1300]: CA is started.
Feb 14 10:20:26ipa-server server[1300]: PKIListener:
org.apache.catalina.core.StandardServer[after_start]
Feb 14 10:20:26ipa-server server[1300]: PKIListener: Subsystem CA is
running.

Regards,
Jens Timmerman

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: OpenPGP digital signature
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20170214/9e931f70/attachment.sig>