#5506 Unable to install third replica
Closed: Fixed None Opened 8 years ago by mbasti.

Topology: master---replica1---replica2

Steps to reproduce:
1. [master] ipa-server-install --setup-dns (no KRA)
2. [replica1] ipa-client-install --server=master
3. [replica1] ipa-replica-install (no DNS, no CA)
4. [replica2] ipa-client-install --server=replica1
5. [replica2; FAIL] ipa-replica-install (no DNS, no CA)

  [18/43]: enabling referential integrity plugin
  [19/43]: configuring certmap.conf
  [20/43]: configure autobind for root
  [21/43]: configure new location for managed entries
  [22/43]: configure dirsrv ccache
  [23/43]: enabling SASL mapping fallback
  [24/43]: restarting directory server
  [25/43]: creating DS keytab
  [26/43]: retrieving DS Certificate
  [27/43]: restarting directory server
ipa         : CRITICAL Failed to restart the directory server (Timeout exceeded). See the installation log for details.
  [28/43]: setting up initial replication
  [error] error: [Errno 111] Connection refused
Your system may be partly configured.

journal

Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert: Configured NSS Ciphers
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_RSA_WITH_AES_128_GCM_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_DSS_WITH_AES_128_GCM_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_RSA_WITH_AES_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_DSS_WITH_AES_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_RSA_WITH_AES_128_CBC_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_DSS_WITH_AES_128_CBC_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_RSA_WITH_CAMELLIA_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_DSS_WITH_CAMELLIA_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_RSA_WITH_AES_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_DSS_WITH_AES_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_RSA_WITH_AES_256_CBC_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_DSS_WITH_AES_256_CBC_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_RSA_WITH_CAMELLIA_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_DHE_DSS_WITH_CAMELLIA_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDH_RSA_WITH_AES_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_ECDH_RSA_WITH_AES_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_RSA_WITH_AES_128_GCM_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_RSA_WITH_AES_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_RSA_WITH_AES_128_CBC_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_RSA_WITH_CAMELLIA_128_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_RSA_WITH_AES_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_RSA_WITH_AES_256_CBC_SHA256: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_RSA_WITH_CAMELLIA_256_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert:         TLS_RSA_WITH_SEED_CBC_SHA: enabled
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert: Security Initialization: Can't find certificate (Server-Cert) for family cn=RSA,cn=encryption,cn=config (Netscape Port
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL alert: Security Initialization: Unable to retrieve private key for cert Server-Cert of family cn=RSA,cn=encryption,cn=config 
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - SSL failure: None of the cipher are valid
Nov 30 19:13:12 replica2.ipa.test ns-slapd[27466]: [30/Nov/2015:19:13:12 +0000] - ERROR: SSL2 Initialization Failed.  Disabling SSL2.
Nov 30 19:13:13 replica2.ipa.test systemd[1]: dirsrv@IPA-TEST.service: main process exited, code=exited, status=1/FAILURE
Nov 30 19:13:13 replica2.ipa.test systemd[1]: Unit dirsrv@IPA-TEST.service entered failed state.
Nov 30 19:13:13 replica2.ipa.test systemd[1]: dirsrv@IPA-TEST.service failed.

Installing replica on the same machine works if it was done against master.


I was albe to reproduce the bug on my setup (master1 w/ CA <-> replica1 w/o CA <-> replica2 w/o CA). Additional excerpts from ipareplica-install.log and systemd journal indicate that certmonger is trying to issue a request to replica1 which does not have CA configured. This of course fails horribly.

ipareplica-install.log

2015-12-01T09:17:55Z DEBUG   [26/43]: retrieving DS Certificate
2015-12-01T09:17:55Z DEBUG Loading Index file from '/var/lib/ipa/sysrestore/sysrestore.index'
2015-12-01T09:17:55Z DEBUG Starting external process
2015-12-01T09:17:55Z DEBUG args='/usr/bin/certutil' '-d' '/etc/dirsrv/slapd-IPA-TEST/' '-L' '-n' 'IPA.TEST IPA CA' '-a'
2015-12-01T09:17:55Z DEBUG Process finished, return code=255
2015-12-01T09:17:55Z DEBUG stdout=
2015-12-01T09:17:55Z DEBUG stderr=certutil: Could not find cert: IPA.TEST IPA CA
: PR_FILE_NOT_FOUND_ERROR: File not found

2015-12-01T09:17:55Z DEBUG Starting external process
2015-12-01T09:17:55Z DEBUG args='/usr/bin/certutil' '-d' '/etc/dirsrv/slapd-IPA-TEST/' '-N' '-f' '/etc/dirsrv/slapd-IPA-TEST//pwdfile.txt'
2015-12-01T09:17:55Z DEBUG Process finished, return code=0
2015-12-01T09:17:55Z DEBUG stdout=
2015-12-01T09:17:55Z DEBUG stderr=
2015-12-01T09:17:55Z DEBUG Starting external process
2015-12-01T09:17:55Z DEBUG args='/usr/bin/certutil' '-d' '/etc/dirsrv/slapd-IPA-TEST/' '-A' '-n' 'IPA.TEST IPA CA' '-t' 'CT,C,C' '-a'
2015-12-01T09:17:55Z DEBUG Process finished, return code=0
2015-12-01T09:17:55Z DEBUG stdout=
2015-12-01T09:17:55Z DEBUG stderr=
2015-12-01T09:17:55Z DEBUG certmonger request is in state dbus.String(u'NEWLY_ADDED_READING_KEYINFO', variant_level=1)
2015-12-01T09:18:00Z DEBUG certmonger request is in state dbus.String(u'CA_UNREACHABLE', variant_level=1)

systemd journal:

-- Logs begin at Tue 2015-12-01 07:33:28 UTC, end at Tue 2015-12-01 09:28:25 UTC. --
Dec 01 08:02:07 client1.ipa.test systemd[1]: Starting Certificate monitoring and PKI enrollment...
Dec 01 08:02:07 client1.ipa.test systemd[1]: Started Certificate monitoring and PKI enrollment.
Dec 01 08:02:08 client1.ipa.test ipa-submit[7329]: GSSAPI client step 1
Dec 01 08:02:08 client1.ipa.test ipa-submit[7329]: GSSAPI client step 1
Dec 01 08:02:08 client1.ipa.test ipa-submit[7329]: GSSAPI client step 1
Dec 01 08:02:08 client1.ipa.test ipa-submit[7329]: GSSAPI client step 1
Dec 01 08:02:08 client1.ipa.test ipa-submit[7329]: GSSAPI client step 2
Dec 01 08:02:20 client1.ipa.test certmonger[7775]: Certificate named "Server-Cert" in token "NSS Certificate DB" in database "/etc/dirsrv/slapd-IPA-TEST" issued by CA and saved.
Dec 01 08:02:44 client1.ipa.test certmonger[8118]: Certificate named "Server-Cert" in token "NSS Certificate DB" in database "/etc/httpd/alias" issued by CA and saved.
Dec 01 08:26:47 client1.ipa.test systemd[1]: Stopping Certificate monitoring and PKI enrollment...
Dec 01 08:26:47 client1.ipa.test systemd[1]: Stopped Certificate monitoring and PKI enrollment.
Dec 01 08:26:48 client1.ipa.test systemd[1]: Starting Certificate monitoring and PKI enrollment...
Dec 01 08:26:48 client1.ipa.test systemd[1]: Started Certificate monitoring and PKI enrollment.
Dec 01 08:26:49 client1.ipa.test systemd[1]: Stopping Certificate monitoring and PKI enrollment...
Dec 01 08:26:49 client1.ipa.test systemd[1]: Stopped Certificate monitoring and PKI enrollment.
Dec 01 08:26:49 client1.ipa.test systemd[1]: Starting Certificate monitoring and PKI enrollment...
Dec 01 08:26:49 client1.ipa.test systemd[1]: Started Certificate monitoring and PKI enrollment.
Dec 01 08:26:49 client1.ipa.test systemd[1]: Stopping Certificate monitoring and PKI enrollment...
Dec 01 08:26:49 client1.ipa.test systemd[1]: Stopped Certificate monitoring and PKI enrollment.
Dec 01 08:26:50 client1.ipa.test systemd[1]: Starting Certificate monitoring and PKI enrollment...
Dec 01 08:26:50 client1.ipa.test systemd[1]: Started Certificate monitoring and PKI enrollment.
Dec 01 08:26:50 client1.ipa.test systemd[1]: Stopping Certificate monitoring and PKI enrollment...
Dec 01 08:26:50 client1.ipa.test systemd[1]: Stopped Certificate monitoring and PKI enrollment.
Dec 01 08:26:50 client1.ipa.test systemd[1]: Starting Certificate monitoring and PKI enrollment...
Dec 01 08:26:50 client1.ipa.test systemd[1]: Started Certificate monitoring and PKI enrollment.
Dec 01 08:27:01 client1.ipa.test systemd[1]: Stopping Certificate monitoring and PKI enrollment...
Dec 01 08:27:01 client1.ipa.test systemd[1]: Stopped Certificate monitoring and PKI enrollment.
Dec 01 08:52:23 client1.ipa.test systemd[1]: Stopped Certificate monitoring and PKI enrollment.
Dec 01 09:17:44 client1.ipa.test systemd[1]: Starting Certificate monitoring and PKI enrollment...
Dec 01 09:17:44 client1.ipa.test systemd[1]: Started Certificate monitoring and PKI enrollment.
Dec 01 09:17:44 client1.ipa.test ipa-submit[30236]: GSSAPI client step 1
Dec 01 09:17:44 client1.ipa.test ipa-submit[30236]: GSSAPI client step 1
Dec 01 09:17:44 client1.ipa.test ipa-submit[30236]: GSSAPI client step 1
Dec 01 09:17:44 client1.ipa.test ipa-submit[30236]: GSSAPI client step 1
Dec 01 09:17:45 client1.ipa.test ipa-submit[30236]: GSSAPI client step 2
Dec 01 09:17:56 client1.ipa.test ipa-submit[30670]: GSSAPI client step 1
Dec 01 09:17:56 client1.ipa.test ipa-submit[30670]: GSSAPI client step 1
Dec 01 09:17:56 client1.ipa.test ipa-submit[30670]: GSSAPI client step 1
Dec 01 09:17:56 client1.ipa.test ipa-submit[30670]: GSSAPI client step 1
Dec 01 09:17:56 client1.ipa.test ipa-submit[30670]: GSSAPI client step 2
Dec 01 09:17:56 client1.ipa.test certmonger[30233]: 2015-12-01 09:17:56 [30233] Server at https://replica1.ipa.test/ipa/xml failed request, will retry: 4301 (RPC failed at server.  Certificate operation cannot be completed: Unable to communicate with CMS (Not Found)).

I wonder what would happen in following scenario, assuming it would not fail during DS install:

  • master with CA <--> replica 1(no CA) <--> replica 2 (CA)

I would say that installation of replica with CA should fail if --server master is replica without CA. Without --server master it should always pick a master with CA.

master:

  • a497288 replica install: improvements in the handling of CA-related IPA config entries

Metadata Update from @mbasti:
- Issue assigned to mbabinsk
- Issue set to the milestone: FreeIPA 4.3

7 years ago

Login to comment on this ticket.

Metadata