#7590 lightweight subca: ca-show fails on replica
Closed: fixed a year ago Opened a year ago by ksiddiqu.

Issue

ipa ca-show fails on replica with following error message.

ipa: ERROR: Failed to authenticate to CA REST API

Note: ipa ca-find works fine.

[root@dhcp207-73 ~]# ipa ca-find

2 CAs matched

Name: ipa
Description: IPA CA
Authority ID: 9744fcf6-54eb-49d0-9252-37fb5eb7c2a6
Subject DN: CN=Certificate Authority,O=TESTRELM.TEST
Issuer DN: CN=Certificate Authority,O=TESTRELM.TEST

Name: test_subca
Authority ID: 703f797d-0043-4210-a05e-bc93906f91ac
Subject DN: CN=test_subca
Issuer DN: CN=Certificate Authority,O=TESTRELM.TEST


Number of entries returned 2

[root@dhcp207-73 ~]#

Steps to Reproduce

  1. Install Master
  2. Install Replica
  3. Run ipa ca-show on replica.

Actual behavior

it fails

Expected behavior

ipa ca-show should be successful

Version/Release/Distribution

[root@dhcp207-73 ~]# rpm -q freeipa-server freeipa-client ipa-server ipa-client 389-ds-base pki-ca krb5-server
freeipa-server-4.6.90test-0.fc28.x86_64
freeipa-client-4.6.90test-0.fc28.x86_64
package ipa-server is not installed
package ipa-client is not installed
389-ds-base-1.4.0.9-2.fc28.x86_64
pki-ca-10.6.1-3.fc28.noarch
krb5-server-1.16.1-4.fc28.x86_64
[root@dhcp207-73 ~]#

Additional info:

Following seen in error_log of apache on replica.

[Tue Jun 19 15:01:46.359121 2018] [:warn] [pid 24820:tid 140301901436672] [client 10.65.207.73:60018] failed to set perms (3140) on file (/var/run/ipa/ccaches/admin@TESTRELM.TEST)!, referer: https://dhcp207-73.testrelm.test/ipa/xml
[Tue Jun 19 15:01:46.420303 2018] [wsgi:error] [pid 24418:tid 140302131074816] [remote 10.65.207.73:60018] ipa: INFO: [jsonserver_session] admin@TESTRELM.TEST: ping(): SUCCESS
[Tue Jun 19 15:01:46.428773 2018] [:warn] [pid 24820:tid 140301993756416] [client 10.65.207.73:60018] failed to set perms (3140) on file (/var/run/ipa/ccaches/admin@TESTRELM.TEST)!, referer: https://dhcp207-73.testrelm.test/ipa/xml
[Tue Jun 19 15:01:46.929133 2018] [proxy:error] [pid 24820:tid 140301893043968] (111)Connection refused: AH00957: AJP: attempt to connect to 127.0.0.1:8009 (localhost) failed
[Tue Jun 19 15:01:46.929450 2018] [proxy_ajp:error] [pid 24820:tid 140301893043968] [client 10.65.207.73:60024] AH00896: failed to make connection to backend: localhost
[Tue Jun 19 15:01:46.931534 2018] [wsgi:error] [pid 24420:tid 140302131074816] [remote 10.65.207.73:60018] ipa: INFO: [jsonserver_session] admin@TESTRELM.TEST: ca_show/1('test_subca', version='2.229'): RemoteRetrieveError


Thanks for the bug report.

I have a couple of questions:

  • Where did you get freeipa-server-4.6.90test-0.fc28.x86_64 and which version/git commit of FreeIPA does the package contain?
  • What's your jss version? Any version < 4.4.4 is buggy and breaks Sub CAs.
  • How did you install the master and the replica? You didn't specify the commands. Did you install master and replica with or without CA?
  • On which machine did you create the Sub CA?
  • On which machine did you run ipa ca-show?
  • Where did you get freeipa-server-4.6.90test-0.fc28.x86_64 and which version/git commit of FreeIPA does the package contain?

  • What's your jss version? Any version < 4.4.4 is buggy and breaks Sub CAs.

    • jss-4.4.4-1.fc28.x86_64
  • How did you install the master and the replica? You didn't specify the commands. Did you install master and replica with or without CA?

    • Both master and replica with CA
    • ipa-server-install -n testrelm.test -r TESTRELM.TEST -p xxxxxxx -a xxxxxxx --domain-level=1 -U --setup-dns --auto-forwarders --auto-reverse
    • Replica install
      • ipa-client-install -U --domain testrelm.test --realm TESTRELM.TEST -p admin -w xxxxxxxx --server dhcp207-43.testrelm.test
      • ipa-replica-install -p xxxxxxxx -w xxxxxxxx -U --setup-ca --ip-address 10.65.207.73 -r TESTRELM.TEST
  • On which machine did you create the Sub CA?

    • on Master
  • On which machine did you run ipa ca-show?

    • on Replica

I'm able to reproduce the issue with an extended test, see https://github.com/freeipa/freeipa/pull/2050

ipa ca-show test_subca_master on replica

HTTP error.log on replica

[Wed Jun 20 11:44:49.410673 2018] [proxy:error] [pid 21324:tid 140703246046976] (111)Connection refused: AH00957: AJP: attempt to connect to 127.0.0.1:8009 (localhost) failed
[Wed Jun 20 11:44:49.410715 2018] [proxy_ajp:error] [pid 21324:tid 140703246046976] [client 192.168.121.208:58418] AH00896: failed to make connection to backend: localhost
[Wed Jun 20 11:44:49.416677 2018] [wsgi:error] [pid 21297:tid 140703141963520] [remote 192.168.121.208:58414] ipa: INFO: [jsonserver_session] admin@IPA.TEST: ca_show/1('test_subca_master', version='2.229'): RemoteRetrieveError

journald on replica

Jun 20 11:44:28 replica0.ipa.test /stop_pkicad[21567]: Stopping pki_tomcatd
Jun 20 11:44:28 replica0.ipa.test systemd[1]: Stopping PKI Tomcat Server pki-tomcat...
Jun 20 11:44:28 replica0.ipa.test server[21589]: Java virtual machine used: /usr/lib/jvm/jre-1.8.0-openjdk/bin/java
Jun 20 11:44:28 replica0.ipa.test server[21589]: classpath used: /usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/lib/java/commons-daemon.jar
Jun 20 11:44:28 replica0.ipa.test server[21589]: main class used: org.apache.catalina.startup.Bootstrap
Jun 20 11:44:28 replica0.ipa.test server[21589]: flags used: -DRESTEASY_LIB=/usr/share/java/resteasy -Djava.library.path=/usr/lib64/nuxwdog-jni
Jun 20 11:44:28 replica0.ipa.test server[21589]: options used: -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=/var/lib/pki/pki-tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Jun 20 11:44:28 replica0.ipa.test server[21589]: arguments used: stop
Jun 20 11:44:30 replica0.ipa.test systemd[1]: Stopped PKI Tomcat Server pki-tomcat.
Jun 20 11:44:30 replica0.ipa.test audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=pki-tomcatd@pki-tomcat comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jun 20 11:44:30 replica0.ipa.test audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=pki-tomcatd@pki-tomcat comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jun 20 11:44:30 replica0.ipa.test /stop_pkicad[21567]: Stopped pki_tomcatd
Jun 20 11:44:36 replica0.ipa.test audit[21617]: AVC avc:  denied  { fowner } for  pid=21617 comm="renew_ca_cert" capability=3  scontext=system_u:system_r:certmonger_t:s0 tcontext=system_u:system_r:certmonger_t:s0 tclass=capability permissive=1
Jun 20 11:44:36 replica0.ipa.test audit[21617]: AVC avc:  denied  { fsetid } for  pid=21617 comm="renew_ca_cert" capability=4  scontext=system_u:system_r:certmonger_t:s0 tcontext=system_u:system_r:certmonger_t:s0 tclass=capability permissive=1
Jun 20 11:44:36 replica0.ipa.test /renew_ca_cert[21617]: Not updating CS.cfg
Jun 20 11:44:36 replica0.ipa.test audit[21632]: AVC avc:  denied  { getattr } for  pid=21632 comm="certutil" name="/" dev="vda1" ino=2 scontext=system_u:system_r:certmonger_t:s0 tcontext=system_u:object_r:fs_t:s0 tclass=filesystem permissive=1
Jun 20 11:44:38 replica0.ipa.test /renew_ca_cert[21617]: Traceback (most recent call last):
                                                           File "/usr/libexec/ipa/certmonger/renew_ca_cert", line 225, in <module>
                                                             main()
                                                           File "/usr/libexec/ipa/certmonger/renew_ca_cert", line 219, in main
                                                             _main()
                                                           File "/usr/libexec/ipa/certmonger/renew_ca_cert", line 184, in _main
                                                             for ca_nick in db.find_root_cert(nickname)[-2:-1]:
                                                           File "/usr/lib/python3.6/site-packages/ipaserver/install/certs.py", line 538, in find_root_cert
                                                             root_nicknames = self.nssdb.get_trust_chain(nickname)
                                                           File "/usr/lib/python3.6/site-packages/ipapython/certdb.py", line 511, in get_trust_chain
                                                             result = self.run_certutil(["-O", "-n", nickname], capture_output=True)
                                                           File "/usr/lib/python3.6/site-packages/ipapython/certdb.py", line 302, in run_certutil
                                                             return ipautil.run(new_args, stdin, cwd=self.secdir, **kwargs)
                                                           File "/usr/lib/python3.6/site-packages/ipapython/ipautil.py", line 572, in run
                                                             p.returncode, arg_string, output_log, error_log
                                                         ipapython.ipautil.CalledProcessError: CalledProcessError(Command ['/usr/bin/certutil', '-d', 'sql:/etc/pki/pki-tomcat/alias', '-O', '-n', 'caSigningCert cert-pki-ca', '-f', '/etc/pki/pki-tomcat/alias/pwdfile.txt'] returned non-zero exit status 255: 'certutil: Could not find: caSigningCert cert-pki-ca\n: PR_FILE_NOT_FOUND_ERROR: File not found\n')
Jun 20 11:44:38 replica0.ipa.test certmonger[21647]: Certificate named "caSigningCert cert-pki-ca" in token "NSS Certificate DB" in database "/etc/pki/pki-tomcat/alias" issued by CA and saved.
Jun 20 11:44:47 replica0.ipa.test audit[13557]: USER_END pid=13557 uid=0 auid=0 ses=7 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=login id=0 exe="/usr/sbin/sshd" hostname=? addr=192.168.121.81 terminal=ssh res=success'
Jun 20 11:44:47 replica0.ipa.test audit[13557]: USER_START pid=13557 uid=0 auid=0 ses=7 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=login id=0 exe="/usr/sbin/sshd" hostname=? addr=192.168.121.81 terminal=ssh res=success'
Jun 20 11:44:47 replica0.ipa.test audit[13557]: CRYPTO_KEY_USER pid=13557 uid=0 auid=0 ses=7 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=SHA256:2b:cb:35:a6:09:00:40:d1:67:a9:7c:bf:78:7f:8d:ac:d7:83:08:85:1d:91:d9:1d:e5:12:18:df:d0:3b:99:34 direction=? spid=21681 suid=0  exe="/usr/sbin/sshd" hostname=? addr=? terminal=? res=success'
Jun 20 11:44:48 replica0.ipa.test audit[17214]: AVC avc:  denied  { sys_ptrace } for  pid=17214 comm="gssproxy" capability=19  scontext=system_u:system_r:gssproxy_t:s0 tcontext=system_u:system_r:gssproxy_t:s0 tclass=capability permissive=1
Jun 20 11:44:49 replica0.ipa.test [21297]: GSSAPI client step 1
Jun 20 11:44:49 replica0.ipa.test [21297]: GSSAPI client step 1
Jun 20 11:44:49 replica0.ipa.test [21297]: GSSAPI client step 1
Jun 20 11:44:49 replica0.ipa.test audit[13557]: USER_END pid=13557 uid=0 auid=0 ses=7 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=login id=0 exe="/usr/sbin/sshd" hostname=? addr=192.168.121.81 terminal=ssh res=success'
Jun 20 11:44:51 replica0.ipa.test /dogtag-ipa-ca-renew-agent-submit[21662]: Forwarding request to dogtag-ipa-renew-agent
Jun 20 11:44:51 replica0.ipa.test /dogtag-ipa-ca-renew-agent-submit[21662]: dogtag-ipa-renew-agent returned 3
Jun 20 11:44:52 replica0.ipa.test certmonger[16380]: 2018-06-20 11:44:52 [16380] Error 7 connecting to http://replica0.ipa.test:8080/ca/ee/ca/profileSubmit: Couldn't connect to server.
Jun 20 11:44:53 replica0.ipa.test /dogtag-ipa-ca-renew-agent-submit[21716]: Forwarding request to dogtag-ipa-renew-agent
Jun 20 11:44:53 replica0.ipa.test /dogtag-ipa-ca-renew-agent-submit[21716]: dogtag-ipa-renew-agent returned 3

Metadata Update from @cheimes:
- Issue assigned to ftweedal
- Issue priority set to: critical
- Issue set to the milestone: FreeIPA 4.7
- Issue tagged with: regression

a year ago

Looking at the trace, it seems we aren't prepared for a missing signing cert when asking to print a chain with -O. This is OK for the 'renew_ca_cert' operation because just few lines above we actually removed the old one and added a newly issued CA cert:

elif nickname == 'caSigningCert cert-pki-ca':

            # Remove old external CA certificates
            for ca_nick, ca_flags in db.list_certs():
                if ca_flags.has_key:
                    continue
                # Delete *all* certificates that use the nickname
                while True:
                    try:
                        db.delete_cert(ca_nick)
                    except ipautil.CalledProcessError:
                        syslog.syslog(
                            syslog.LOG_ERR,
                            "Failed to remove certificate %s" % ca_nick)
                        break
                    if not db.has_nickname(ca_nick):
                        break

...

                for ca_cert, ca_nick, ca_flags in ca_certs:
                    try:
                        db.add_cert(ca_cert, ca_nick, ca_flags)
                    except ipautil.CalledProcessError as e:
                        syslog.syslog(
                            syslog.LOG_ERR,
                            "Failed to add certificate %s" % ca_nick)

                # Pass Dogtag's self-tests
                for ca_nick in db.find_root_cert(nickname)[-2:-1]:
                    ca_flags = dict(cc[1:] for cc in ca_certs)[ca_nick]
                    usages = ca_flags.usages or set()
                    ca_flags_modified = TrustFlags(ca_flags.has_key,
                        True, True,
                        usages | {x509.EKU_SERVER_AUTH})
                    db.trust_root_cert(ca_nick, ca_flags_modified)

So I think we need to wrap a search for the CA nick (db.find_root_cert(nickname)) to handle any exception or make sure lower levels don't leak the CalledProcessError exception and just return empty list instead.

Another JSS commit addresses a similar issue for LWCA key replication:
https://github.com/dogtagpki/jss/pull/15

JSS 4.4.5 will fix the issue for new ipa-replica-install installations as well as migrations from 4.6.4 and earlier. The fix will not repair replicas that have been installedw ith 4.6.90.pre1 and 4.6.90.pre2, though.

master:

  • 6896c90 Extend Sub CA replication test
  • a7627a7 Require JSS 4.4.5 with replication fixes

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

a year ago

Login to comment on this ticket.

Metadata