Bug 1267782

Summary: IPA upgrade fails for server with CA cert signed by external CA
Product: Red Hat Enterprise Linux 7 Reporter: Scott Poore <spoore>
Component: 389-ds-baseAssignee: Noriko Hosoi <nhosoi>
Status: CLOSED WONTFIX QA Contact: Viktor Ashirov <vashirov>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.2CC: jcholast, lkrispen, mattdm, mbasti, nkinder, pvoborni, rcritten, rmeggins, spoore, tbordaz
Target Milestone: rcKeywords: TestBlocker
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1270608 (view as bug list) Environment:
Last Closed: 2017-08-17 20:53:48 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
ipaupgrade.log
none
ipaserver-install.log gzipped
none
dirsrv error log
none
/etc/dirsrv/slapd-EXAMPLE-COM/schema dir none

Description Scott Poore 2015-10-01 00:58:02 UTC 
Description of problem:

Upgrading from IPA on RHEL7.0 to IPA on RHEL7.2, I see failures and dirsrv won't start.

I see this during yum update:

773/773 
2619 blocks
IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
Unexpected error - see /var/log/ipaupgrade.log for details:
CalledProcessError: Command ''/bin/systemctl' 'start' 'dirsrv'' returned non-zero exit status 1
rhel-7.2-server/productid                                                       | 1.6 kB  00:00:00     


Version-Release number of selected component (if applicable):
From: ipa-server-3.3.3-28.el7.x86_64
To: ipa-server-4.2.0-12.el7.x86_64

How reproducible:
Unknown

Steps to Reproduce:
1.  Install IPA on rhel7.0 with external-ca signed cert
2.  Point server to RHEL7.2 repos
3.  yum update

Actual results:
fails

Expected results:


Additional info:
Comment 1 Scott Poore 2015-10-01 01:00:24 UTC 
This is how I installed the IPA server originally:

[root@rhel7-1 ~]# ipa-server-install --setup-dns --forwarder=192.168.122.1 -r EXAMPLE.COM -a Secret123 -p Secret123 --external-ca -U

The log file for this installation can be found in /var/log/ipaserver-install.log
==============================================================================
This program will set up the IPA Server.

This includes:
  * Configure a stand-alone CA (dogtag) for certificate management
  * Configure the Network Time Daemon (ntpd)
  * Create and configure an instance of Directory Server
  * Create and configure a Kerberos Key Distribution Center (KDC)
  * Configure Apache (httpd)
  * Configure DNS (bind)

Warning: skipping DNS resolution of host rhel7-1.example.com
The domain name has been determined based on the host name.

Using reverse zone 122.168.192.in-addr.arpa.

The IPA Master Server will be configured with:
Hostname:      rhel7-1.example.com
IP address:    192.168.122.71
Domain name:   example.com
Realm name:    EXAMPLE.COM

BIND DNS server will be configured to serve IPA domain with:
Forwarders:    192.168.122.1
Reverse zone:  122.168.192.in-addr.arpa.

Configuring NTP daemon (ntpd)
  [1/4]: stopping ntpd
  [2/4]: writing configuration
  [3/4]: configuring ntpd to start on boot
  [4/4]: starting ntpd
Done configuring NTP daemon (ntpd).
Configuring directory server (dirsrv): Estimated time 1 minute
  [1/38]: creating directory server user
  [2/38]: creating directory server instance
  [3/38]: adding default schema
  [4/38]: enabling memberof plugin
  [5/38]: enabling winsync plugin
  [6/38]: configuring replication version plugin
  [7/38]: enabling IPA enrollment plugin
  [8/38]: enabling ldapi
  [9/38]: configuring uniqueness plugin
  [10/38]: configuring uuid plugin
  [11/38]: configuring modrdn plugin
  [12/38]: configuring DNS plugin
  [13/38]: enabling entryUSN plugin
  [14/38]: configuring lockout plugin
  [15/38]: creating indices
  [16/38]: enabling referential integrity plugin
  [17/38]: configuring certmap.conf
  [18/38]: configure autobind for root
  [19/38]: configure new location for managed entries
  [20/38]: configure dirsrv ccache
  [21/38]: enable SASL mapping fallback
  [22/38]: restarting directory server
  [23/38]: adding default layout
  [24/38]: adding delegation layout
  [25/38]: creating container for managed entries
  [26/38]: configuring user private groups
  [27/38]: configuring netgroups from hostgroups
  [28/38]: creating default Sudo bind user
  [29/38]: creating default Auto Member layout
  [30/38]: adding range check plugin
  [31/38]: creating default HBAC rule allow_all
  [32/38]: initializing group membership
  [33/38]: adding master entry
  [34/38]: configuring Posix uid/gid generation
  [35/38]: adding replication acis
  [36/38]: enabling compatibility plugin
  [37/38]: tuning directory server
  [38/38]: configuring directory to start on boot
Done configuring directory server (dirsrv).
Configuring certificate server (pki-tomcatd): Estimated time 3 minutes 30 seconds
  [1/6]: creating certificate server user
  [2/6]: configuring certificate server instance
The next step is to get /root/ipa.csr signed by your CA and re-run ipa-server-install as:
ipa-server-install --external_cert_file=/path/to/signed_certificate --external_ca_file=/path/to/external_ca_certificate

[root@rhel7-1 ~]# CADIR=/root/RootCA

[root@rhel7-1 ~]# mkdir $CADIR

[root@rhel7-1 ~]# cd $CADIR

[root@rhel7-1 RootCA]# rm  -f *

[root@rhel7-1 RootCA]# echo Secret123 > $CADIR/mypass1

[root@rhel7-1 RootCA]# certutil -N -d $CADIR -f $CADIR/mypass1

[root@rhel7-1 RootCA]# SERNUM=$RANDOM

[root@rhel7-1 RootCA]# SERNUM=$(( SERNUM += 1 ))

[root@rhel7-1 RootCA]# echo -e "y\n10\ny\n" | \
> certutil -S -d $CADIR \
>     -n RootCA \
>     -s "CN=MyRootCA, O=fakerealm1" \
>     -x \
>     -t "CTu,CTu,CTu" \
>     -g 2048 \
>     -m $SERNUM\
>     -v 60 \
>     -z /etc/group \
>     -2 \
>     --keyUsage certSigning \
>     --nsCertType sslCA,smimeCA,objectSigningCA \
>     -f $CADIR/mypass1


Generating key.  This may take a few moments...

Is this a CA certificate [y/N]?
Enter the path length constraint, enter to skip [<0 for unlimited path]: > Is this a critical extension [y/N]?
Notice: Trust flag u is set automatically if the private key is present.

[root@rhel7-1 RootCA]# SERNUM=$(( SERNUM += 1 ))

[root@rhel7-1 RootCA]# echo -e "y\n10\ny\n" | \
> certutil -C -d $CADIR \
>     -c RootCA \
>     -m $SERNUM \
>     -v 60 \
>     -2 \
>     --keyUsage digitalSignature,nonRepudiation,certSigning \
>     --nsCertType sslCA,smimeCA,objectSigningCA \
>     -i /root/ipa.csr \
>     -o /root/ipa.crt \
>     -f $CADIR/mypass1 \
>     -a
Is this a CA certificate [y/N]?
Enter the path length constraint, enter to skip [<0 for unlimited path]: > Is this a critical extension [y/N]?

[root@rhel7-1 RootCA]# certutil -L -d $CADIR -n "RootCA" -a >> /root/ipacacert.asc

[root@rhel7-1 RootCA]# cd  /root

[root@rhel7-1 ~]# ipa-server-install --setup-dns --forwarder=192.168.122.1     -r EXAMPLE.COM -a Secret123 -p Secret123     --external_cert_file=/root/ipa.crt     --external_ca_file=/root/ipacacert.asc -U
The log file for this installation can be found in /var/log/ipaserver-install.log
==============================================================================
This program will set up the IPA Server.

This includes:
  * Configure a stand-alone CA (dogtag) for certificate management
  * Configure the Network Time Daemon (ntpd)
  * Create and configure an instance of Directory Server
  * Create and configure a Kerberos Key Distribution Center (KDC)
  * Configure Apache (httpd)
  * Configure DNS (bind)

Warning: skipping DNS resolution of host rhel7-1.example.com
Using reverse zone 122.168.192.in-addr.arpa.

The IPA Master Server will be configured with:
Hostname:      rhel7-1.example.com
IP address:    192.168.122.71
Domain name:   example.com
Realm name:    EXAMPLE.COM

BIND DNS server will be configured to serve IPA domain with:
Forwarders:    192.168.122.1
Reverse zone:  122.168.192.in-addr.arpa.

Configuring certificate server (pki-tomcatd): Estimated time 3 minutes 30 seconds
  [1/22]: creating certificate server user
  [2/22]: configuring certificate server instance
  [3/22]: stopping certificate server instance to update CS.cfg
  [4/22]: disabling nonces
  [5/22]: set up CRL publishing
  [6/22]: starting certificate server instance
  [7/22]: creating RA agent certificate database
  [8/22]: importing CA chain to RA certificate database
  [9/22]: fixing RA database permissions
  [10/22]: setting up signing cert profile
  [11/22]: set certificate subject base
  [12/22]: enabling Subject Key Identifier
  [13/22]: enabling CRL and OCSP extensions for certificates
  [14/22]: setting audit signing renewal to 2 years
  [15/22]: configuring certificate server to start on boot
  [16/22]: restarting certificate server
  [17/22]: requesting RA certificate from CA
  [18/22]: issuing RA agent certificate
  [19/22]: adding RA agent as a trusted user
  [20/22]: configure certificate renewals
  [21/22]: configure Server-Cert certificate renewal
  [22/22]: Configure HTTP to proxy connections
Done configuring certificate server (pki-tomcatd).
Configuring Kerberos KDC (krb5kdc): Estimated time 30 seconds
  [1/10]: adding sasl mappings to the directory
  [2/10]: adding kerberos container to the directory
  [3/10]: configuring KDC
  [4/10]: initialize kerberos container
  [5/10]: adding default ACIs
  [6/10]: creating a keytab for the directory
  [7/10]: creating a keytab for the machine
  [8/10]: adding the password extension to the directory
  [9/10]: starting the KDC
  [10/10]: configuring KDC to start on boot
Done configuring Kerberos KDC (krb5kdc).
Configuring kadmin
  [1/2]: starting kadmin 
  [2/2]: configuring kadmin to start on boot
Done configuring kadmin.
Configuring ipa_memcached
  [1/2]: starting ipa_memcached 
  [2/2]: configuring ipa_memcached to start on boot
Done configuring ipa_memcached.
Configuring ipa-otpd
  [1/2]: starting ipa-otpd 
  [2/2]: configuring ipa-otpd to start on boot
Done configuring ipa-otpd.
Configuring the web interface (httpd): Estimated time 1 minute
  [1/14]: setting mod_nss port to 443
  [2/14]: setting mod_nss password file
  [3/14]: enabling mod_nss renegotiate
  [4/14]: adding URL rewriting rules
  [5/14]: configuring httpd
  [6/14]: setting up ssl
  [7/14]: setting up browser autoconfig
  [8/14]: publish CA cert
  [9/14]: creating a keytab for httpd
  [10/14]: clean up any existing httpd ccache
  [11/14]: configuring SELinux for httpd
  [12/14]: configure httpd ccache
  [13/14]: restarting httpd
  [14/14]: configuring httpd to start on boot
Done configuring the web interface (httpd).
Applying LDAP updates
Restarting the directory server
Restarting the KDC
Restarting the certificate server
Configuring DNS (named)
  [1/11]: adding DNS container
  [2/11]: setting up our zone
  [3/11]: setting up reverse zone
  [4/11]: setting up our own record
  [5/11]: setting up records for other masters
  [6/11]: setting up CA record
  [7/11]: setting up kerberos principal
  [8/11]: setting up named.conf
  [9/11]: restarting named
  [10/11]: configuring named to start on boot
  [11/11]: changing resolv.conf to point to ourselves
Done configuring DNS (named).

Global DNS configuration in LDAP server is empty
You can use 'dnsconfig-mod' command to set global DNS options that
would override settings in local named.conf files

Restarting the web server
==============================================================================
Setup complete

Next steps:
	1. You must make sure these network ports are open:
		TCP Ports:
		  * 80, 443: HTTP/HTTPS
		  * 389, 636: LDAP/LDAPS
		  * 88, 464: kerberos
		  * 53: bind
		UDP Ports:
		  * 88, 464: kerberos
		  * 53: bind
		  * 123: ntp

	2. You can now obtain a kerberos ticket using the command: 'kinit admin'
	   This ticket will allow you to use the IPA tools (e.g., ipa user-add)
	   and the web user interface.

Be sure to back up the CA certificate stored in /root/cacert.p12
This file is required to create replicas. The password for this
file is the Directory Manager password
Comment 2 Scott Poore 2015-10-01 01:04:44 UTC 
Created attachment 1078871 [details]
ipaupgrade.log
Comment 4 Scott Poore 2015-10-01 01:07:12 UTC 
Created attachment 1078872 [details]
ipaserver-install.log gzipped
Comment 5 Jan Cholasta 2015-10-01 05:51:12 UTC 
Scott, could you please attach /var/log/dirsrv/slapd-EXAMPLE-COM/errors and output of:

$ journalctl -u dirsrv
$ certutil -d /etc/dirsrv/slapd-EXAMPLE-COM -L
$ certutil -d /etc/dirsrv/slapd-EXAMPLE-COM -O -n Server-Cert

?
Comment 6 Scott Poore 2015-10-01 12:41:19 UTC 
[root@rhel7-1 ~]# ipactl status
Directory Service: STOPPED
Directory Service must be running in order to obtain status of other services
ipa: INFO: The ipactl command was successful

[root@rhel7-1 ~]# journalctl -u dirsrv
-- Logs begin at Thu 2015-10-01 07:37:02 CDT, end at Thu 2015-10-01 07:37:30 CDT. --

[root@rhel7-1 ~]# ipactl start
Upgrade required: please run ipa-server-upgrade command
Aborting ipactl

[root@rhel7-1 ~]# ipa-server-upgrade
session memcached servers not running
Missing version: no platform stored
Upgrading IPA:
  [1/8]: saving configuration
  [2/8]: disabling listeners
  [3/8]: enabling DS global lock
  [4/8]: starting directory server
  [error] CalledProcessError: Command ''/bin/systemctl' 'start' 'dirsrv'' returned non-zero exit status 1
  [cleanup]: stopping directory server
  [cleanup]: restoring configuration
IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
Unexpected error - see /var/log/ipaupgrade.log for details:
CalledProcessError: Command ''/bin/systemctl' 'start' 'dirsrv'' returned non-zero exit status 1

[root@rhel7-1 ~]# journalctl -u dirsrv
-- Logs begin at Thu 2015-10-01 07:37:02 CDT, end at Thu 2015-10-01 07:38:42 CDT. --
Oct 01 07:38:42 rhel7-1.example.com systemd[1]: Starting 389 Directory Server EXAMPLE-COM....
Oct 01 07:38:42 rhel7-1.example.com ns-slapd[10362]: [01/Oct/2015:07:38:42 -0500] - Cannot find parent 
Oct 01 07:38:42 rhel7-1.example.com ns-slapd[10362]: [01/Oct/2015:07:38:42 -0500] dse_read_one_file - T
Oct 01 07:38:42 rhel7-1.example.com ns-slapd[10362]: [01/Oct/2015:07:38:42 -0500] dse - Please edit the
Oct 01 07:38:42 rhel7-1.example.com systemd[1]: dirsrv: control process exited, cod
Oct 01 07:38:42 rhel7-1.example.com systemd[1]: Failed to start 389 Directory Server EXAMPLE-COM..
Oct 01 07:38:42 rhel7-1.example.com systemd[1]: Unit dirsrv entered failed state.
Oct 01 07:38:42 rhel7-1.example.com systemd[1]: dirsrv failed.
Oct 01 07:38:42 rhel7-1.example.com systemd[1]: Stopped 389 Directory Server EXAMPLE-COM..
[root@rhel7-1 ~]# 

[root@rhel7-1 ~]# certutil -d /etc/dirsrv/slapd-EXAMPLE-COM -L

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

EXAMPLE.COM IPA CA                                           CT,,C
Server-Cert                                                  u,u,u
CN=MyRootCA,O=fakerealm1                                     CT,,C
CN=IPA RA,O=EXAMPLE.COM                                      CT,,C

[root@rhel7-1 ~]# certutil -d /etc/dirsrv/slapd-EXAMPLE-COM -O -n Server-Cert
"CN=MyRootCA,O=fakerealm1" [CN=MyRootCA,O=fakerealm1]

  "EXAMPLE.COM IPA CA" [CN=Certificate Authority,O=EXAMPLE.COM]

    "Server-Cert" [CN=rhel7-1.example.com,O=EXAMPLE.COM]

[root@rhel7-1 ~]#
Comment 7 Scott Poore 2015-10-01 12:41:36 UTC 
Created attachment 1079089 [details]
dirsrv error log
Comment 8 Jan Cholasta 2015-10-01 12:49:13 UTC 
These lines from journal look relevant but they are truncated:

ct 01 07:38:42 rhel7-1.example.com ns-slapd[10362]: [01/Oct/2015:07:38:42 -0500] - Cannot find parent 
Oct 01 07:38:42 rhel7-1.example.com ns-slapd[10362]: [01/Oct/2015:07:38:42 -0500] dse_read_one_file - T
Oct 01 07:38:42 rhel7-1.example.com ns-slapd[10362]: [01/Oct/2015:07:38:42 -0500] dse - Please edit the

Could you please post them in full length?
Comment 9 Jan Cholasta 2015-10-01 12:50:10 UTC 
Nevermind, it's in the error log you attached.
Comment 10 Jan Cholasta 2015-10-01 14:47:23 UTC 
Scott, could you please post the output of:

# grep -in publickey /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif

?
Comment 11 Scott Poore 2015-10-01 16:46:28 UTC 
[root@rhel7-1 ~]# grep -in publickey /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif
169: ecovery $ algorithm $ publicKeyFormat $ publicKeyData $ archivedBy $ clientId
186: top STRUCTURAL MUST ( cn $ nisPublickey $ nisSecretkey ) MAY ( uidNumber $ de
209:objectClasses: ( 2.16.840.1.113730.3.8.12.24 NAME 'ipaPublicKeyObject' DESC 'W
210: rapped public keys' SUP top AUXILIARY MUST ipaPublicKey X-ORIGIN ( 'IPA v4.2.
229:  ipaVaultPublicKey $ owner $ member ) X-ORIGIN ( 'IPA v4.2.0' 'user defined' 
252: Template $ ipk11AlwaysAuthenticate $ ipk11PublicKeyInfo ) X-ORIGIN ( 'IPA v4.
254:objectClasses: ( 2.16.840.1.113730.3.8.17.2.6 NAME 'ipk11PublicKey' DESC 'Publ
257: Distrusted $ ipk11PublicKeyInfo ) X-ORIGIN ( 'IPA v4.2.0' 'user defined' ) )
274: UCTURAL MUST ( cn $ ipaCertIssuerSerial $ ipaCertSubject $ ipaPublicKey ) MAY
423:attributeTypes: ( 2.16.840.1.113730.3.8.17.1.20 NAME 'ipk11PublicKeyInfo' DESC
424:  'DER-encoding of SubjectPublicKeyInfo of associated public key' EQUALITY oct
489:attributeTypes: ( 2.16.840.1.113730.3.8.18.2.3 NAME 'ipaVaultPublicKey' DESC '
490: IPA vault public key' SUP ipaPublicKey EQUALITY octetStringMatch SYNTAX 1.3.6
492:attributeTypes: ( publicKeyFormat-oid NAME 'publicKeyFormat' DESC 'CMS defined
578:attributeTypes: ( publicKeyData-oid NAME 'publicKeyData' DESC 'CMS defined att
1010:attributeTypes: ( 2.16.840.1.113730.3.8.11.53 NAME 'ipaPublicKey' DESC 'Public
1011:  key as DER-encoded SubjectPublicKeyInfo (RFC 5280)' EQUALITY octetStringMatc
1205:attributeTypes: ( 1.3.6.1.1.1.1.28 NAME 'nisPublickey' DESC 'nisPublickey' EQU
[root@rhel7-1 ~]#
Comment 12 Jan Cholasta 2015-10-02 05:32:36 UTC 
If you edit 99user.ldif by cutting the attribute type on line 489 (ipaVaultPublicKey) and pasting it after the attribute type on line 1010 (ipaPublicKey), does ipa-server-upgrade work afterwards?
Comment 13 Scott Poore 2015-10-02 15:39:03 UTC 
I saw the same error on a simple self-signed install on 7.0 upgraded to 7.2.  

I tried your suggestion in comment #12 and it got farther but, still failing to start dirsrv:

[root@rhel7-9 ~]# ipa-server-upgrade 
session memcached servers not running
Missing version: no platform stored
Upgrading IPA:
  [1/8]: saving configuration
  [2/8]: disabling listeners
  [3/8]: enabling DS global lock
  [4/8]: starting directory server
  [error] CalledProcessError: Command ''/bin/systemctl' 'start' 'dirsrv'' returned non-zero exit status 1
  [cleanup]: stopping directory server
  [cleanup]: restoring configuration
IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
Unexpected error - see /var/log/ipaupgrade.log for details:
CalledProcessError: Command ''/bin/systemctl' 'start' 'dirsrv'' returned non-zero exit status 1
[root@rhel7-9 ~]# grep -in publickey /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif
169: ecovery $ algorithm $ publicKeyFormat $ publicKeyData $ archivedBy $ clientId
186: top STRUCTURAL MUST ( cn $ nisPublickey $ nisSecretkey ) MAY ( uidNumber $ de
209:objectClasses: ( 2.16.840.1.113730.3.8.12.24 NAME 'ipaPublicKeyObject' DESC 'W
210: rapped public keys' SUP top AUXILIARY MUST ipaPublicKey X-ORIGIN ( 'IPA v4.2.
229:  ipaVaultPublicKey $ owner $ member ) X-ORIGIN ( 'IPA v4.2.0' 'user defined' 
252: Template $ ipk11AlwaysAuthenticate $ ipk11PublicKeyInfo ) X-ORIGIN ( 'IPA v4.
254:objectClasses: ( 2.16.840.1.113730.3.8.17.2.6 NAME 'ipk11PublicKey' DESC 'Publ
257: Distrusted $ ipk11PublicKeyInfo ) X-ORIGIN ( 'IPA v4.2.0' 'user defined' ) )
274: UCTURAL MUST ( cn $ ipaCertIssuerSerial $ ipaCertSubject $ ipaPublicKey ) MAY
423:attributeTypes: ( 2.16.840.1.113730.3.8.17.1.20 NAME 'ipk11PublicKeyInfo' DESC
424:  'DER-encoding of SubjectPublicKeyInfo of associated public key' EQUALITY oct
489:attributeTypes: ( 2.16.840.1.113730.3.8.18.2.3 NAME 'ipaVaultPublicKey' DESC '
490: IPA vault public key' SUP ipaPublicKey EQUALITY octetStringMatch SYNTAX 1.3.6
492:attributeTypes: ( publicKeyFormat-oid NAME 'publicKeyFormat' DESC 'CMS defined
578:attributeTypes: ( publicKeyData-oid NAME 'publicKeyData' DESC 'CMS defined att
1010:attributeTypes: ( 2.16.840.1.113730.3.8.11.53 NAME 'ipaPublicKey' DESC 'Public
1011:  key as DER-encoded SubjectPublicKeyInfo (RFC 5280)' EQUALITY octetStringMatc
1205:attributeTypes: ( 1.3.6.1.1.1.1.28 NAME 'nisPublickey' DESC 'nisPublickey' EQU
[root@rhel7-9 ~]# cp /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif /tmp/orig.99user.ldif

[root@rhel7-9 ~]# vi /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif

[root@rhel7-9 ~]# ipa-server-upgrade 
session memcached servers not running
Missing version: no platform stored
Upgrading IPA:
  [1/8]: saving configuration
  [2/8]: disabling listeners
  [3/8]: enabling DS global lock
  [4/8]: starting directory server
  [5/8]: updating schema
  [6/8]: upgrading server
  [7/8]: stopping directory server
  [8/8]: restoring configuration
Done.
Update complete
Upgrading IPA services
Upgrading the configuration of the IPA services
IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
Unexpected error - see /var/log/ipaupgrade.log for details:
CalledProcessError: Command ''/bin/systemctl' 'start' 'dirsrv'' returned non-zero exit status 1

[root@rhel7-9 ~]#  diff /tmp/orig.99user.ldif /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif
9c9
< modifyTimestamp: 20151002152503Z
---
> modifyTimestamp: 20151002153437Z
372a373,375
> attributeTypes: ( 2.16.840.1.113730.3.8.11.59 NAME 'ipaKeyUsage' DESC 'Allowed
>   key usage' EQUALITY caseIgnoreMatch SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 X-O
>  RIGIN ( 'IPA v4.1' 'user defined' ) )
377,379d379
< attributeTypes: ( 2.16.840.1.113730.3.8.11.59 NAME 'ipaKeyUsage' DESC 'Allowed
<   key usage' EQUALITY caseIgnoreMatch SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 X-O
<  RIGIN ( 'IPA v4.1' 'user defined' ) )
1172,1175d1171
< attributeTypes: ( 1.3.6.1.4.1.2428.20.4 NAME 'UnknownRecord' DESC 'unknown DNS
<   record, RFC 3597' EQUALITY caseIgnoreIA5Match SUBSTR caseIgnoreIA5Substrings
<  Match SYNTAX 1.3.6.1.4.1.1466.115.121.1.26 X-ORIGIN ( 'IPA v4.2.0' 'user defi
<  ned' ) )
1179a1176,1179
> attributeTypes: ( 1.3.6.1.4.1.2428.20.4 NAME 'UnknownRecord' DESC 'unknown DNS
>   record, RFC 3597' EQUALITY caseIgnoreIA5Match SUBSTR caseIgnoreIA5Substrings
>  Match SYNTAX 1.3.6.1.4.1.1466.115.121.1.26 X-ORIGIN ( 'IPA v4.2.0' 'user defi
>  ned' ) )
1235c1235
< nsSchemaCSN: 560ea1cf000000000000
---
> nsSchemaCSN: 560ea40d000000000000
Comment 14 Scott Poore 2015-10-02 17:53:32 UTC 
FYI, I also got the same result when I tried again with external-ca install.
Comment 15 Jan Cholasta 2015-10-05 05:32:44 UTC 
This bug is caused by a faulty schema upgrade, it's not related to the CA.

According to the grep output in comment 13, ipaVaultPublicKey is still on line 489. I'm going to assume that you have made the changes to 99user.ldif as I requested, but DS changed it back later.

Ludwig, this looks like a DS bug, could you please help us investigate it? When upgrading from RHEL 7.0 to 7.2, we add two new attribute types, ipaPublicKey and ipaVaultPublicKey, which inherits from ipaPublicKey. The issue is that despite ipaPublicKey is added in a separate LDAP MOD before ipaVaultPublicKey, they are stored in the wrong order in 99user.ldif, which prevents DS from starting.
Comment 17 thierry bordaz 2015-10-05 12:42:45 UTC 
Hello,

would you please attach the schema (/etc/dirsrv/slapd-EXAMPLE-COM/schema/*) to the case or can I get access to your host ?

thanks
Comment 18 Scott Poore 2015-10-05 12:54:01 UTC 
Created attachment 1079925 [details]
/etc/dirsrv/slapd-EXAMPLE-COM/schema dir
Comment 19 Scott Poore 2015-10-05 12:54:40 UTC 
Thierry, 

I attached the schema.  I'll also send you details on login if you need that too.

Thanks,
Scott
Comment 20 thierry bordaz 2015-10-05 13:27:04 UTC 
The problem was the order of AttributeTypes definitions in 99user.ldif.

I did change 99user.ldif
[root@rhel7-9 schema]# pwd
/etc/dirsrv/slapd-EXAMPLE-COM/schema
[root@rhel7-9 schema]# diff 99user.ldif 99user.ldif.sav
489,492d488
< attributeTypes: ( 2.16.840.1.113730.3.8.11.53 NAME 'ipaPublicKey' DESC 'Public
<   key as DER-encoded SubjectPublicKeyInfo (RFC 5280)' EQUALITY octetStringMatc
<  h SYNTAX 1.3.6.1.4.1.1466.115.121.1.40 X-ORIGIN ( 'IPA v4.1' 'user defined' )
<   )
1013a1010,1013
> attributeTypes: ( 2.16.840.1.113730.3.8.11.53 NAME 'ipaPublicKey' DESC 'Public
>   key as DER-encoded SubjectPublicKeyInfo (RFC 5280)' EQUALITY octetStringMatc
>  h SYNTAX 1.3.6.1.4.1.1466.115.121.1.40 X-ORIGIN ( 'IPA v4.1' 'user defined' )
>   )


So that 'ipaPublicKey' is defined before being used in 'ipaVaultPublicKey' definition.

After that change, DS started successfully.
Comment 21 Jan Cholasta 2015-10-05 14:04:28 UTC 
Yes, we already know that, see comment 11. We also know that editing 99user.ldif does not fix the issue permanently, see comment 13.
Comment 22 thierry bordaz 2015-10-05 15:29:42 UTC 
Looking at /var/log/dirsrv/slapd-EXAMPLE-COM/errors and /var/log/ipaupgrade.log


   - The "killing" update occurs between 15:24:53Z and 15:26:05
[02/Oct/2015:10:24:53 -0500] - slapd started.  Listening on /var/run/slapd-EXAMPLE-COM.socket for LDAPI requests
...
[02/Oct/2015:10:26:05 -0500] - All database threads now stopped
[02/Oct/2015:10:26:07 -0500] - Cannot find parent attribute type "ipaPublicKey"
[02/Oct/2015:10:26:07 -0500] dse_read_one_file - The entry cn=schema in file /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif (lineno: 1) is invalid, error code 21 (Invalid syntax) - attribute type ipaVaultPublicKey: Missing parent attribute syntax OID
[02/Oct/2015:10:26:07 -0500] dse - Please edit the file to correct the reported problems and then restart the server.
[02/Oct/2015:10:31:10 -0500] - Cannot find parent attribute type "ipaPublicKey"
[02/Oct/2015:10:31:10 -0500] dse_read_one_file - The entry cn=schema in file /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif (lineno: 1) is invalid, error code 21 (Invalid syntax) - attribute type ipaVaultPublicKey: Missing parent attribute syntax OID


   - The updates are adding definitions ipaPublicKey then ipaVaultPublicKey (60basev3.ldif).
233 2015-10-02T15:24:55Z DEBUG Processing schema LDIF file /usr/share/ipa/60basev3.ldif
...
246 2015-10-02T15:24:55Z DEBUG Add: ( 2.16.840.1.113730.3.8.11.53 NAME 'ipaPublicKey' DESC 'Public key as DER-encoded SubjectPub        licKeyInfo (RFC 5280)' EQUALITY octetStringMatch SYNTAX 1.3.6.1.4.1.1466.115.121.1.40 X-ORIGIN 'IPA v4.1' )
..
256 2015-10-02T15:24:55Z DEBUG Schema modlist:
257 [(0,
258   u'attributetypes',
259   ["( 2.16.840.1.113730.3.8.11.53 NAME 'ipaPublicKey' DESC 'Public key as DER-encoded SubjectPublicKeyInfo (RFC 5280)' EQUAL        ITY octetStringMatch SYNTAX 1.3.6.1.4.1.1466.115.121.1.40 X-ORIGIN 'IPA v4.1' )",
...
280 2015-10-02T15:24:56Z DEBUG Add: ( 2.16.840.1.113730.3.8.18.2.3 NAME 'ipaVaultPublicKey' DESC 'IPA vault public key' SUP ipaP        ublicKey X-ORIGIN 'IPA v4.2' )
281 2015-10-02T15:24:56Z DEBUG Schema modlist:
282 [(0,
283   u'attributetypes',
284   ["( 2.16.840.1.113730.3.8.18.2.3 NAME 'ipaVaultPublicKey' DESC 'IPA vault public key' SUP ipaPublicKey X-ORIGIN 'IPA v4.2'         )"])]

  - These updates are done locally (upgrade process I guess), not through replication
[02/Oct/2015:10:24:53 -0500] conn=2 fd=65 slot=65 connection from local to /var/run/slapd-EXAMPLE-COM.socket
[02/Oct/2015:10:24:53 -0500] conn=1 op=-1 fd=64 closed - B1
[02/Oct/2015:10:24:53 -0500] conn=2 AUTOBIND dn="cn=Directory Manager"
...
[02/Oct/2015:10:24:54 -0500] conn=2 op=3 MOD dn="cn=schema"
[02/Oct/2015:10:24:54 -0500] conn=2 op=3 RESULT err=0 tag=103 nentries=0 etime=0
...
[02/Oct/2015:10:24:59 -0500] conn=2 op=20 MOD dn="cn=schema"
[02/Oct/2015:10:24:59 -0500] conn=2 op=20 RESULT err=0 tag=103 nentries=0 etime=0



  - What are the MOD operations ? (MOD_ADD I assum)
    ipaVaultPublicKey is added after ipaPublicKey.
    Does it assume that the value ipaVaultPublicKey will be stored after ipaPublicKey ?
Comment 23 Scott Poore 2015-10-05 15:49:34 UTC 
Can someone from IPA Dev answer Thierry's question?
Comment 24 Jan Cholasta 2015-10-06 05:30:50 UTC 
Yes, it's MOD_ADD.

ipaVaultPublicKey must be added after ipaPublicKey, because ipaVaultPublicKey inherits from ipaPublicKey.

It does not assume anything about how the values are stored (that's DS's bussiness after all), only that storing them will not break DS.
Comment 26 Jan Cholasta 2015-10-08 08:42:26 UTC 
This demonstrates that the bug is in DS:


# rpm -q 389-ds-base ipa-server
389-ds-base-1.3.4.0-19.el7.x86_64
ipa-server-4.2.0-12.el7.x86_64

# ipa-server-install
...

# systemctl restart dirsrv@EXAMPLE-COM

# systemctl status dirsrv@EXAMPLE-COM -l
● dirsrv - 389 Directory Server EXAMPLE-COM.
   Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; static; vendor preset: disabled)
   Active: active (running) since Thu 2015-10-08 10:18:18 CEST; 1s ago
  Process: 30220 ExecStopPost=/bin/rm -f /var/run/dirsrv/slapd-%i.pid (code=exited, status=0/SUCCESS)
  Process: 30222 ExecStart=/usr/sbin/ns-slapd -D /etc/dirsrv/slapd-%i -i /var/run/dirsrv/slapd-%i.pid -w /var/run/dirsrv/slapd-%i.startpid (code=exited, status=0/SUCCESS)
 Main PID: 30224 (ns-slapd)
   CGroup: /system.slice/system-dirsrv.slice/dirsrv
           └─30224 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-EXAMPLE-COM -i /var/run/dirsrv/slapd-EXAMPLE-COM.pid -w /var/run/dirsrv/slapd-EXAMPLE-COM.startpid

Oct 08 10:18:18 ipa.example.com systemd[1]: Starting 389 Directory Server EXAMPLE-COM....
Oct 08 10:18:18 ipa.example.com systemd[1]: Started 389 Directory Server EXAMPLE-COM..

# ldapmodify -H ldap://ipa.example.com -D 'cn=Directory Manager' -W
Enter LDAP Password: 
dn: cn=schema
changetype: modify
add: attributeTypes
attributeTypes: (2.16.840.1.113730.3.8.999.12 NAME 'testAttr1' EQUALITY octetStringMatch SYNTAX 1.3.6.1.4.1.1466.115.121.1.40)

modifying entry "cn=schema"

dn: cn=schema
changetype: modify
add: attributeTypes
attributeTypes: (2.16.840.1.113730.3.8.999.11 NAME 'testAttr1Subtype' SUP testAttr1)

modifying entry "cn=schema"

# systemctl restart dirsrv@EXAMPLE-COM
Job for dirsrv failed because the control process exited with error code. See "systemctl status dirsrv" and "journalctl -xe" for details.

# systemctl status dirsrv@EXAMPLE-COM -l
● dirsrv - 389 Directory Server EXAMPLE-COM.
   Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; static; vendor preset: disabled)
   Active: failed (Result: exit-code) since Thu 2015-10-08 10:28:09 CEST; 23s ago
  Process: 30334 ExecStopPost=/bin/rm -f /var/run/dirsrv/slapd-%i.pid (code=exited, status=0/SUCCESS)
  Process: 30336 ExecStart=/usr/sbin/ns-slapd -D /etc/dirsrv/slapd-%i -i /var/run/dirsrv/slapd-%i.pid -w /var/run/dirsrv/slapd-%i.startpid (code=exited, status=1/FAILURE)
 Main PID: 30224 (code=exited, status=0/SUCCESS)

Oct 08 10:28:09 ipa.example.com systemd[1]: Starting 389 Directory Server EXAMPLE-COM....
Oct 08 10:28:09 ipa.example.com ns-slapd[30336]: [08/Oct/2015:10:28:09 +0200] - Cannot find parent attribute type "testAttr1"
Oct 08 10:28:09 ipa.example.com ns-slapd[30336]: [08/Oct/2015:10:28:09 +0200] dse_read_one_file - The entry cn=schema in file /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif (lineno: 1) is invalid, error code 21 (Invalid syntax) - attribute type testAttr1Subtype: Missing parent attribute syntax OID
Oct 08 10:28:09 ipa.example.com ns-slapd[30336]: [08/Oct/2015:10:28:09 +0200] dse - Please edit the file to correct the reported problems and then restart the server.
Oct 08 10:28:09 ipa.example.com systemd[1]: dirsrv: control process exited, code=exited status=1
Oct 08 10:28:09 ipa.example.com systemd[1]: Failed to start 389 Directory Server EXAMPLE-COM..
Oct 08 10:28:09 ipa.example.com systemd[1]: Unit dirsrv entered failed state.
Oct 08 10:28:09 ipa.example.com systemd[1]: dirsrv failed.

# vim /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif
(move testAttr1Subtype definition after testAttr1 definition)

# systemctl restart dirsrv@EXAMPLE-COM

# systemctl status dirsrv@EXAMPLE-COM
● dirsrv - 389 Directory Server EXAMPLE-COM.
   Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; static; vendor preset: disabled)
   Active: active (running) since Thu 2015-10-08 10:34:38 CEST; 1min 5s ago
  Process: 30334 ExecStopPost=/bin/rm -f /var/run/dirsrv/slapd-%i.pid (code=exited, status=0/SUCCESS)
  Process: 30376 ExecStart=/usr/sbin/ns-slapd -D /etc/dirsrv/slapd-%i -i /var/run/dirsrv/slapd-%i.pid -w /var/run/dirsrv/slapd-%i.startpid (code=exited, status=0/SUCCESS)
 Main PID: 30377 (ns-slapd)
   CGroup: /system.slice/system-dirsrv.slice/dirsrv
           └─30377 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-EXAMPLE-COM -i /var/run/dirsrv/slapd-EXAMPLE-COM.pid -w /var/run/dirsrv/slapd-EXAMPLE-COM.startpid

Oct 08 10:34:38 ipa.example.com systemd[1]: Starting 389 Directory Server EXAMPLE-COM....
Oct 08 10:34:38 ipa.example.com systemd[1]: Started 389 Directory Server EXAMPLE-COM..

# ldapmodify -H ldap://ipa.example.com -D 'cn=Directory Manager' -W
Enter LDAP Password: 
dn: cn=schema
changetype: modify
add: attributeTypes
attributeTypes: (2.16.840.1.113730.3.8.999.21 NAME 'testAttr2' EQUALITY octetStringMatch SYNTAX 1.3.6.1.4.1.1466.115.121.1.40)

modifying entry "cn=schema"

# systemctl restart dirsrv@EXAMPLE-COM
Job for dirsrv failed because the control process exited with error code. See "systemctl status dirsrv" and "journalctl -xe" for details.

# systemctl status dirsrv@EXAMPLE-COM -l
● dirsrv - 389 Directory Server EXAMPLE-COM.
   Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; static; vendor preset: disabled)
   Active: failed (Result: exit-code) since Thu 2015-10-08 10:38:51 CEST; 27s ago
  Process: 30449 ExecStopPost=/bin/rm -f /var/run/dirsrv/slapd-%i.pid (code=exited, status=0/SUCCESS)
  Process: 30451 ExecStart=/usr/sbin/ns-slapd -D /etc/dirsrv/slapd-%i -i /var/run/dirsrv/slapd-%i.pid -w /var/run/dirsrv/slapd-%i.startpid (code=exited, status=1/FAILURE)
 Main PID: 30377 (code=exited, status=0/SUCCESS)

Oct 08 10:38:51 ipa.example.com systemd[1]: Starting 389 Directory Server EXAMPLE-COM....
Oct 08 10:38:51 ipa.example.com ns-slapd[30451]: [08/Oct/2015:10:38:51 +0200] - Cannot find parent attribute type "testAttr1"
Oct 08 10:38:51 ipa.example.com ns-slapd[30451]: [08/Oct/2015:10:38:51 +0200] dse_read_one_file - The entry cn=schema in file /etc/dirsrv/slapd-EXAMPLE-COM/schema/99user.ldif (lineno: 1) is invalid, error code 21 (Invalid syntax) - attribute type testAttr1Subtype: Missing parent attribute syntax OID
Oct 08 10:38:51 ipa.example.com ns-slapd[30451]: [08/Oct/2015:10:38:51 +0200] dse - Please edit the file to correct the reported problems and then restart the server.
Oct 08 10:38:51 ipa.example.com systemd[1]: dirsrv: control process exited, code=exited status=1
Oct 08 10:38:51 ipa.example.com systemd[1]: Failed to start 389 Directory Server EXAMPLE-COM..
Oct 08 10:38:51 ipa.example.com systemd[1]: Unit dirsrv entered failed state.
Oct 08 10:38:51 ipa.example.com systemd[1]: dirsrv failed.


Changing the component to 389-ds-base.
Comment 27 thierry bordaz 2015-10-08 10:19:29 UTC 
I can reproduce the described behaviour independently to freeipa.
In fact when doing a MOD_ADD, it rewrites the schema file based on an avl_tree built with the current and added values.

The order of the values is not guarantee. However I have to investigate a bit more to check if we have this possibility with the avl_tree.

Regarding the protocol (https://tools.ietf.org/html/rfc4511#section-4.1.7), the application should not rely on order of attribute (attributetypes) values. 
"..The set of attribute values is unordered.
   Implementations MUST NOT rely upon the ordering being repeatable."

I understand that it is problematic for freeipa and will check if we can not guarantee that the ADDED value can not be added at the last position.

Would it be possible to change the upgrade script to do MOD_REPLACE ?
Comment 28 Jan Cholasta 2015-10-08 10:56:12 UTC 
IPA does not depend on ordering of the values in any way.

This is not a protocol issue, this is a DS backend issue - it writes data that it is unable to read back correctly.

I will let Martin Bašti answer the upgrade script question.
Comment 29 Martin Bašti 2015-10-08 11:07:26 UTC 
Replace MOD_ADD with MOD_REPLACE requires big changes in IPA code, and it will not fix the issue, because user can manually add his own schema, it will result in broken DS again.
Comment 30 Jan Cholasta 2015-10-08 11:25:11 UTC 
I found this comment at <https://fedorahosted.org/389/browser/ldap/servers/slapd/schema.c#L1125>:

    We need to keep the objectclasses in the same order as defined in the ldif files. If not
    SUP dependencies will break. When the user redefines an existing objectclass this code
    makes sure it is put back in the same order it was read to from the ldif file. It also
    verifies that the entries oc_superior value preceeds it in the chain. If not it will not
    allow the entry to be added. This makes sure that the ldif will be written back correctly.

This must be done for attribute types as well, they can have SUP dependencies too, otherwise you will see errors like we are seeing here with ipaVaultPublicKey.
Comment 31 thierry bordaz 2015-10-08 14:49:53 UTC 
DS handles attributetypes and objectclasses differently.

Objectclasses are stored internally in a list and new oc are added at the end. https://bugzilla.redhat.com/show_bug.cgi?id=1267782#c30 is related to replacement of an existing oc (not adding a new one) and then the oc is replaced a the same slot in the list to preserve SUP dependancy.
Basically objectclasses is working fine because new oc are appended

attributetypes are stored internally in a hash table. The table is enumerated to create the schema ldif files and the order they get enumerated does not rely on order the attributetype are added.
I think moving away from a hashtable to a list (like objectclasses) should fix the current problem.

The fix is not immediate and I have to evaluate the impact of such change.
Comment 32 thierry bordaz 2015-10-08 15:24:34 UTC 
The fix I am thinking of is too big and risky for 7.2. I would suggest to try workarounds:
  - (preferred) remove the SUP dependency in ipaVaultPublicKey
( 2.16.840.1.113730.3.8.18.2.3 NAME 'ipaVaultPublicKey' DESC 'IPA vault public key' X-ORIGIN 'IPA v4.2' )
 - Try MOD_REPLACE (in place of MOD_ADD) as I believe it could fix this issue. Now this is a large change for IPA upgrade scripts so it is not the preferred workaround
Comment 34 Noriko Hosoi 2015-10-12 16:16:31 UTC 
Upstream ticket:
https://fedorahosted.org/389/ticket/48307
Comment 35 Noriko Hosoi 2016-06-03 17:21:25 UTC 
Thank you for your confirmation, Thierry.
> For 1267782 there is a workaround so it is ok to push it to 7.4

Pushing to 7.4.
Comment 37 Nathan Kinder 2017-08-17 20:53:48 UTC 
It is believed that this issue is not valid anymore, and the upstream ticket was closed some time ago.  Closing as WONTFIX.  If this issue does persist in testing, we can reopen it and evaluate it.