[Freeipa-users] Upgrade/Migration steps

Fri Jun 21 20:39:28 UTC 2013

On Friday, June 21, 2013 09:26:36 Rob Crittenden wrote:
> We'd need to see /var/log/ipareplica-install.log to see what the LDAP
> error is. If you look on the remote master DS access log it may have
> additional information on what was requested.

Logs attached.

10.10.0.50 is the new replica.

No metion the new replica in the error logs.  At least not that I can see.

-- 
Joshua J. Kugler - Fairbanks, Alaska
Azariah Enterprises - Programming and Website Design
joshua at azariah.com - Jabber: pedahzur at gmail.com
PGP Key: http://pgp.mit.edu/  ID 0x73B13B6A
-------------- next part --------------
2013-06-21T20:11:58Z DEBUG /usr/sbin/ipa-replica-install was invoked with argument "replica-info-ipan.lab.whamcloud.com.gpg" and options: {'no_forwarders': False, 'conf_ssh': True, 'setup_ca': True, 'ui_redirect': True, 'reverse_zone': None, 'trust_sshfp': False, 'unattended': False, 'setup_pkinit': True, 'no_host_dns': False, 'mkhomedir': False, 'ip_address': None, 'no_reverse': False, 'setup_dns': False, 'create_sshfp': True, 'conf_sshd': True, 'forwarders': None, 'debug': False, 'conf_ntp': False, 'skip_conncheck': True, 'skip_schema_check': False}
2013-06-21T20:11:58Z DEBUG Loading Index file from '/var/lib/ipa-client/sysrestore/sysrestore.index'
2013-06-21T20:11:58Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2013-06-21T20:11:58Z DEBUG Loading Index file from '/var/lib/ipa/sysrestore/sysrestore.index'
2013-06-21T20:12:10Z DEBUG Starting external process
2013-06-21T20:12:10Z DEBUG args=/usr/bin/gpg --batch --homedir /tmp/tmpi9cPa4ipa/ipa-hRix5l/.gnupg --passphrase-fd 0 --yes --no-tty -o /tmp/tmpi9cPa4ipa/files.tar -d replica-info-ipan.lab.whamcloud.com.gpg
2013-06-21T20:12:10Z DEBUG Process finished, return code=0
2013-06-21T20:12:10Z DEBUG stdout=
2013-06-21T20:12:10Z DEBUG stderr=gpg: WARNING: unsafe permissions on homedir `/tmp/tmpi9cPa4ipa/ipa-hRix5l/.gnupg'
gpg: keyring `/tmp/tmpi9cPa4ipa/ipa-hRix5l/.gnupg/secring.gpg' created
gpg: keyring `/tmp/tmpi9cPa4ipa/ipa-hRix5l/.gnupg/pubring.gpg' created
gpg: CAST5 encrypted data
gpg: encrypted with 1 passphrase
gpg: WARNING: message was not integrity protected

2013-06-21T20:12:10Z DEBUG Starting external process
2013-06-21T20:12:10Z DEBUG args=tar xf /tmp/tmpi9cPa4ipa/files.tar -C /tmp/tmpi9cPa4ipa
2013-06-21T20:12:10Z DEBUG Process finished, return code=0
2013-06-21T20:12:10Z DEBUG stdout=
2013-06-21T20:12:10Z DEBUG stderr=
2013-06-21T20:12:10Z DEBUG Installing replica file with version 0 (0 means no version in prepared file).
2013-06-21T20:12:10Z DEBUG Check if ipan.lab.whamcloud.com is a primary hostname for localhost
2013-06-21T20:12:10Z DEBUG Primary hostname for localhost: ipan.lab.whamcloud.com
2013-06-21T20:12:10Z DEBUG Search DNS for ipan.lab.whamcloud.com
2013-06-21T20:12:10Z DEBUG Check if ipan.lab.whamcloud.com is not a CNAME
2013-06-21T20:12:10Z DEBUG Check reverse address of 10.10.0.50
2013-06-21T20:12:10Z DEBUG Found reverse name: ipan.lab.whamcloud.com
2013-06-21T20:12:10Z DEBUG Check if ipa0.lab.whamcloud.com is a primary hostname for localhost
2013-06-21T20:12:10Z DEBUG Primary hostname for localhost: ipa0.lab.whamcloud.com
2013-06-21T20:12:10Z DEBUG Search DNS for ipa0.lab.whamcloud.com
2013-06-21T20:12:10Z DEBUG Check if ipa0.lab.whamcloud.com is not a CNAME
2013-06-21T20:12:10Z DEBUG Check reverse address of 10.10.0.4
2013-06-21T20:12:10Z DEBUG Found reverse name: ipa0.lab.whamcloud.com
2013-06-21T20:12:10Z DEBUG Starting external process
2013-06-21T20:12:10Z DEBUG args=/sbin/ip -family inet -oneline address show
2013-06-21T20:12:10Z DEBUG Process finished, return code=0
2013-06-21T20:12:10Z DEBUG stdout=1: lo    inet 127.0.0.1/8 scope host lo\       valid_lft forever preferred_lft forever
2: eth0    inet 10.10.0.50/16 brd 10.10.255.255 scope global eth0\       valid_lft forever preferred_lft forever

2013-06-21T20:12:10Z DEBUG stderr=
2013-06-21T20:12:10Z DEBUG importing all plugin modules in '/usr/lib/python2.7/site-packages/ipalib/plugins'...
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/aci.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/automember.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/automount.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/baseldap.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/batch.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/cert.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/config.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/delegation.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/dns.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/entitle.py'
2013-06-21T20:12:10Z DEBUG skipping plugin module ipalib.plugins.entitle: No module named rhsm.connection
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/group.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/hbacrule.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/hbacsvc.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/hbacsvcgroup.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/hbactest.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/host.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/hostgroup.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/idrange.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/internal.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/kerberos.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/krbtpolicy.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/migration.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/misc.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/netgroup.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/passwd.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/permission.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/ping.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/pkinit.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/privilege.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/pwpolicy.py'
2013-06-21T20:12:10Z DEBUG Starting external process
2013-06-21T20:12:10Z DEBUG args=klist -V
2013-06-21T20:12:10Z DEBUG Process finished, return code=0
2013-06-21T20:12:10Z DEBUG stdout=Kerberos 5 version 1.10.3

2013-06-21T20:12:10Z DEBUG stderr=
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/realmdomains.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/role.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/selfservice.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/selinuxusermap.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/service.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/sudocmd.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/sudocmdgroup.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/sudorule.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/trust.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/user.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/virtual.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/xmlclient.py'
2013-06-21T20:12:10Z DEBUG importing all plugin modules in '/usr/lib/python2.7/site-packages/ipaserver/install/plugins'...
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipaserver/install/plugins/adtrust.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipaserver/install/plugins/baseupdate.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipaserver/install/plugins/dns.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipaserver/install/plugins/fix_replica_agreements.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipaserver/install/plugins/rename_managed.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipaserver/install/plugins/update_anonymous_aci.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipaserver/install/plugins/update_services.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipaserver/install/plugins/updateclient.py'
2013-06-21T20:12:10Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipaserver/install/plugins/upload_cacrt.py'
2013-06-21T20:12:11Z DEBUG ds group dirsrv exists
2013-06-21T20:12:11Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
2013-06-21T20:12:11Z DEBUG Created connection context.ldap2_51326288
2013-06-21T20:12:11Z DEBUG flushing ldaps://ipa0.lab.whamcloud.com:636 from SchemaCache
2013-06-21T20:12:11Z DEBUG retrieving schema for SchemaCache url=ldaps://ipa0.lab.whamcloud.com:636 conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x21a45a8>
2013-06-21T20:12:12Z DEBUG flushing ldaps://ipa0.lab.whamcloud.com from SchemaCache
2013-06-21T20:12:12Z DEBUG retrieving schema for SchemaCache url=ldaps://ipa0.lab.whamcloud.com conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x21a4d88>
2013-06-21T20:12:12Z DEBUG Created connection context.ldap2
2013-06-21T20:12:12Z DEBUG Destroyed connection context.ldap2
2013-06-21T20:12:12Z DEBUG No IPA DNS servers, skipping forward/reverse resolution check
2013-06-21T20:12:12Z DEBUG Destroyed connection context.ldap2_51326288
2013-06-21T20:12:12Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2013-06-21T20:12:12Z DEBUG Checking if IPA schema is present in ldap://ipa0.lab.whamcloud.com:7389
2013-06-21T20:12:12Z CRITICAL CA DS schema check failed. Make sure the PKI service on the remote master is operational.
2013-06-21T20:12:12Z INFO   File "/usr/lib/python2.7/site-packages/ipaserver/install/installutils.py", line 619, in run_script
    return_value = main_function()

  File "/usr/sbin/ipa-replica-install", line 640, in main
    cainstance.replica_ca_install_check(config, dogtag_master_ds_port)

  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 1725, in replica_ca_install_check
    connection.start_tls_s()

  File "/usr/lib/python2.7/site-packages/ipaserver/plugins/ldap2.py", line 625, in start_tls_s
    return self.conn.start_tls_s()

  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 564, in start_tls_s
    return self._ldap_call(self._l.start_tls_s)

  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 99, in _ldap_call
    result = func(*args,**kwargs)

2013-06-21T20:12:12Z INFO The ipa-replica-install command failed, exception: PROTOCOL_ERROR: {'info': 'unsupported extended operation', 'desc': 'Protocol error'}
-------------- next part --------------
[21/Jun/2013:13:26:54 -0700] conn=24643 fd=290 slot=290 SSL connection from 10.10.0.50 to 10.10.0.4
[21/Jun/2013:13:26:54 -0700] conn=24643 SSL 256-bit AES
[21/Jun/2013:13:26:54 -0700] conn=24643 op=0 BIND dn="cn=directory manager" method=128 version=3
[21/Jun/2013:13:26:54 -0700] conn=24643 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=directory manager"
[21/Jun/2013:13:26:54 -0700] conn=24644 fd=292 slot=292 SSL connection from 10.10.0.50 to 10.10.0.4
[21/Jun/2013:13:26:54 -0700] conn=24644 SSL 256-bit AES
[21/Jun/2013:13:26:54 -0700] conn=24644 op=0 BIND dn="cn=directory manager" method=128 version=3
[21/Jun/2013:13:26:54 -0700] conn=24644 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=directory manager"
[21/Jun/2013:13:26:54 -0700] conn=24644 op=1 SRCH base="cn=config,cn=ldbm database,cn=plugins,cn=config" scope=0 filter="(objectClass=*)" attrs="nsslapd-directory"
[21/Jun/2013:13:26:54 -0700] conn=24644 op=1 RESULT err=0 tag=101 nentries=1 etime=0
[21/Jun/2013:13:26:54 -0700] conn=24644 op=2 SRCH base="cn=schema" scope=0 filter="(objectClass=*)" attrs="attributeTypes objectClasses"
[21/Jun/2013:13:26:54 -0700] conn=24644 op=2 RESULT err=0 tag=101 nentries=1 etime=0
[21/Jun/2013:13:26:54 -0700] conn=24643 op=1 SRCH base="cn=ipaconfig,cn=etc,dc=lab,dc=whamcloud,dc=com" scope=0 filter="(objectClass=*)" attrs=ALL
[21/Jun/2013:13:26:54 -0700] conn=24643 op=1 RESULT err=0 tag=101 nentries=1 etime=0
[21/Jun/2013:13:26:54 -0700] conn=24643 op=2 SRCH base="cn=schema" scope=0 filter="(objectClass=*)" attrs="attributeTypes objectClasses"
[21/Jun/2013:13:26:54 -0700] conn=24643 op=2 RESULT err=0 tag=101 nentries=1 etime=0
[21/Jun/2013:13:26:54 -0700] conn=24645 fd=293 slot=293 connection from 10.10.2.31 to 10.10.0.4
[21/Jun/2013:13:26:54 -0700] conn=24645 op=0 BIND dn="" method=128 version=3
[21/Jun/2013:13:26:54 -0700] conn=24645 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn=""
[21/Jun/2013:13:26:54 -0700] conn=24643 op=3 SRCH base="cn=computers,cn=accounts,dc=lab,dc=whamcloud,dc=com" scope=2 filter="(fqdn=ipan.lab.whamcloud.com)" attrs="distinguishedName fqdn"
[21/Jun/2013:13:26:54 -0700] conn=24643 op=3 RESULT err=0 tag=101 nentries=0 etime=0 notes=U
[21/Jun/2013:13:26:54 -0700] conn=24646 fd=294 slot=294 SSL connection from 10.10.0.50 to 10.10.0.4
[21/Jun/2013:13:26:54 -0700] conn=24645 op=1 SRCH base="DC=lab,DC=whamcloud,DC=com" scope=2 filter="(&(objectClass=posixAccount)(uid=root))" attrs=ALL
[21/Jun/2013:13:26:54 -0700] conn=24645 op=1 RESULT err=0 tag=101 nentries=0 etime=0
[21/Jun/2013:13:26:54 -0700] conn=24645 op=2 SRCH base="DC=lab,DC=whamcloud,DC=com" scope=2 filter="(&(objectClass=posixGroup)(memberUid=root))" attrs="gidNumber"
[21/Jun/2013:13:26:54 -0700] conn=24645 op=2 RESULT err=0 tag=101 nentries=0 etime=0 notes=P
[21/Jun/2013:13:26:54 -0700] conn=24645 op=-1 fd=293 closed - B1
[21/Jun/2013:13:26:54 -0700] conn=24646 SSL 256-bit AES
[21/Jun/2013:13:26:54 -0700] conn=24646 op=0 BIND dn="cn=directory manager" method=128 version=3
[21/Jun/2013:13:26:54 -0700] conn=24646 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=directory manager"
[21/Jun/2013:13:26:54 -0700] conn=24646 op=1 SRCH base="cn=masters,cn=ipa,cn=etc,dc=lab,dc=whamcloud,dc=com" scope=2 filter="(&(objectClass=ipaConfigObject)(cn=DNS))" attrs=ALL
[21/Jun/2013:13:26:54 -0700] conn=24646 op=1 RESULT err=0 tag=101 nentries=0 etime=0
[21/Jun/2013:13:26:54 -0700] conn=24646 op=2 UNBIND
[21/Jun/2013:13:26:54 -0700] conn=24646 op=2 fd=294 closed - U1
[21/Jun/2013:13:26:54 -0700] conn=24643 op=4 SRCH base="cn=meToipan.lab.whamcloud.com,cn=replica,cn=dc\3Dlab\2Cdc\3Dwhamcloud\2Cdc\3Dcom,cn=mapping tree,cn=config" scope=0 filter="(objectClass=*)" attrs="* aci"
[21/Jun/2013:13:26:54 -0700] conn=24643 op=4 RESULT err=32 tag=101 nentries=0 etime=0
[21/Jun/2013:13:26:54 -0700] conn=24643 op=5 UNBIND
[21/Jun/2013:13:26:54 -0700] conn=24643 op=5 fd=290 closed - U1
[21/Jun/2013:13:26:54 -0700] conn=24644 op=3 UNBIND
[21/Jun/2013:13:26:54 -0700] conn=24644 op=3 fd=292 closed - U1
-------------- next part --------------
[21/Jun/2013:13:26:54 -0700] conn=53 fd=64 slot=64 connection from 10.10.0.50 to 10.10.0.4
[21/Jun/2013:13:26:54 -0700] conn=53 op=0 EXT oid="1.3.6.1.4.1.1466.20037"
[21/Jun/2013:13:26:54 -0700] conn=53 op=0 RESULT err=2 tag=120 nentries=0 etime=0
[21/Jun/2013:13:26:54 -0700] conn=53 op=1 UNBIND