[Freeipa-users] ipa upgrade failed
Martin Basti
mbasti at redhat.com
Fri Oct 2 10:28:56 UTC 2015
On 10/01/2015 07:50 PM, Andrew E. Bruno wrote:
> On Thu, Oct 01, 2015 at 05:40:34PM +0200, Martin Basti wrote:
>>
>> On 10/01/2015 05:28 PM, Andrew E. Bruno wrote:
>>> On Thu, Oct 01, 2015 at 05:09:23PM +0200, Martin Basti wrote:
>>>> On 10/01/2015 05:03 PM, Andrew E. Bruno wrote:
>>>>> Running CentOS 7.1.1503.
>>>>>
>>>>> Upgrading via yum update from:
>>>>>
>>>>> ipa-server.x86_64 0:4.1.0-18.el7.centos.3
>>>>>
>>>>> --to--
>>>>>
>>>>> ipa-server.x86_64 0:4.1.0-18.el7.centos.4
>>>>>
>>>>> We have 3 replicates. Upgrading the first replicate (first-master) went
>>>>> fine. Upgrading the second replicate failed.
>>>>>
>>>>> Got the following error during the update on the second replicate:
>>>>>
>>>>> Pre schema upgrade failed with [Errno 111] Connection refused
>>>>> IPA upgrade failed.
>>>>>
>>>>> Where should I look for more info? Looked in the usual places and didn't
>>>>> see anything out of the ordinary. How can I fix/verify the upgrade?
>>>>>
>>>>> Thanks!
>>>>>
>>>>> --Andrew
>>>>>
>>>> Hello,
>>>>
>>>> can you check /var/log/ipaupgrade.log and /var/log/dirsrv/slapd-*/errors for
>>>> more specific errors?
>>> Here's the errors from /var/log/dirsrv/slapd-*/errors right around the time of the upgrade:
>>>
>>> [01/Oct/2015:10:42:37 -0400] - slapd shutting down - signaling operation threads - op stack size 84 max work q size 59 max work q stack size 59
>>> [01/Oct/2015:10:44:50 -0400] - Information: Non-Secure Port Disabled
>>> [01/Oct/2015:10:44:50 -0400] - 389-Directory/1.3.3.1 B2015.218.023 starting up
>>> [01/Oct/2015:10:44:50 -0400] - WARNING: changelog: entry cache size 512000B is less than db size 28639232B; We recommend to increase the entry cache size nsslapd-cachememsize.
>>> [01/Oct/2015:10:44:50 -0400] - Detected Disorderly Shutdown last time Directory Server was running, recovering database.
>>> ...
>>> tion.
>>> [01/Oct/2015:10:45:03 -0400] NSMMReplicationPlugin - changelog program - _cl5NewDBFile: PR_DeleteSemaphore: /var/lib/dirsrv/slapd-INT-CCR-BUFFALO-EDU/cldb/9fc73292-2b0911e5-a53bd3a1-f3bbc58c.sema; NSPR error - -5943
>>> [01/Oct/2015:10:45:08 -0400] NSMMReplicationPlugin - changelog program - _cl5NewDBFile: PR_DeleteSemaphore: /var/lib/dirsrv/slapd-INT-CCR-BUFFALO-EDU/cldb/d0a7671e-2b0911e5-a53bd3a1-f3bbc58c.sema; NSPR error - -5943
>>> [01/Oct/2015:10:45:08 -0400] NSMMReplicationPlugin - replica_check_for_data_reload: Warning: disordely shutdown for replica o=ipaca. Check if DB RUV needs to be updated
>>> [01/Oct/2015:10:45:08 -0400] set_krb5_creds - Could not get initial credentials for principal [ldap/srv-d13-39-02.int.ccr.buffalo.edu at INT.CCR.BUFFALO.EDU] in keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328324 (Generic error (see e-text))
>>> [01/Oct/2015:10:45:08 -0400] NSMMReplicationPlugin - agmt="cn=cloneAgreement1-srv-d13-39-02.int.ccr.buffalo.edu-pki-tomcat" (srv-d13-38-02:389): Unable to acquire replica: the replica instructed us to go into backoff mode. Will retry later.
>>> [01/Oct/2015:10:45:08 -0400] NSMMReplicationPlugin - replica_check_for_data_reload: Warning: disordely shutdown for replica dc=int,dc=ccr,dc=buffalo,dc=edu. Check if DB RUV needs to be updated
>>> [01/Oct/2015:10:45:08 -0400] slapd_ldap_sasl_interactive_bind - Error: could not perform interactive bind for id [] mech [GSSAPI]: LDAP error -2 (Local error) (SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (No Kerberos credentials available)) errno 0 (Success)
>>> ...
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22231 (rc: 32)
>>> [01/Oct/2015:10:45:09 -0400] - slapd started. Listening on /var/run/slapd-INT-CCR-BUFFALO-EDU.socket for LDAPI requests
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22232 (rc: 32)
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22233 (rc: 32)
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22234 (rc: 32)
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22235 (rc: 32)
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22236 (rc: 32)
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22237 (rc: 32)
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22238 (rc: 32)
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22239 (rc: 32)
>>> [01/Oct/2015:10:45:09 -0400] DSRetroclPlugin - delete_changerecord: could not delete change record 22240 (rc: 32)
>>> ..
>>>
>>>
>>> These delete_changerecord are repeated all the way to 321722.
>>>
>>>
>>> Here's the errors from /var/log/ipaupgrade.log
>>>
>>>
>>> 2015-10-01T14:44:49Z DEBUG [4/10]: starting directory server
>>> 2015-10-01T14:44:49Z DEBUG Starting external process
>>> 2015-10-01T14:44:49Z DEBUG args='/bin/systemctl' 'start' 'dirsrv at INT-CCR-BUFFALO-EDU.service'
>>> 2015-10-01T14:44:50Z DEBUG Process finished, return code=0
>>> 2015-10-01T14:44:50Z DEBUG stdout=
>>> 2015-10-01T14:44:50Z DEBUG stderr=
>>> 2015-10-01T14:44:50Z DEBUG duration: 0 seconds
>>> 2015-10-01T14:44:50Z DEBUG [5/10]: preparing server upgrade
>>> 2015-10-01T14:45:00Z ERROR Pre schema upgrade failed with [Errno 111] Connection refused
>>> 2015-10-01T14:45:00Z DEBUG Traceback (most recent call last):
>>> File "/usr/lib/python2.7/site-packages/ipaserver/install/upgradeinstance.py", line 128, in __pre_schema_upgrade
>>> ld = ldapupdate.LDAPUpdate(dm_password='', ldapi=True, live_run=self.live_run, plugins=True)
>>> File "/usr/lib/python2.7/site-packages/ipaserver/install/ldapupdate.py", line 220, in __init__
>>> self.create_connection()
>>> File "/usr/lib/python2.7/site-packages/ipaserver/install/ldapupdate.py", line 783, in create_connection
>>> dm_password=self.dm_password, pw_name=self.pw_name)
>>> File "/usr/lib/python2.7/site-packages/ipaserver/install/ldapupdate.py", line 65, in connect
>>> conn.do_external_bind(pw_name)
>>> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1761, in do_external_bind
>>> self.conn.sasl_interactive_bind_s, timeout, None, auth_tokens)
>>> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1747, in __bind_with_wait
>>> self.__wait_for_connection(timeout)
>>> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1733, in __wait_for_connection
>>> wait_for_open_socket(lurl.hostport, timeout)
>>> File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 1173, in wait_for_open_socket
>>> raise e
>>> error: [Errno 111] Connection refused
>>>
>>> 2015-10-01T14:45:00Z DEBUG duration: 10 seconds
>>> 2015-10-01T14:45:00Z DEBUG [6/10]: updating schema
>>>
>>> ...
>>>
>>> 2015-10-01T14:45:43Z DEBUG duration: 2 seconds
>>> 2015-10-01T14:45:43Z DEBUG [9/10]: restoring configuration
>>> 2015-10-01T14:45:43Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
>>> 2015-10-01T14:45:43Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
>>> 2015-10-01T14:45:43Z DEBUG duration: 0 seconds
>>> 2015-10-01T14:45:43Z DEBUG [10/10]: starting directory server
>>> 2015-10-01T14:45:43Z DEBUG Starting external process
>>> 2015-10-01T14:45:43Z DEBUG args='/bin/systemctl' 'start' 'dirsrv at INT-CCR-BUFFALO-EDU.service'
>>> 2015-10-01T14:45:44Z DEBUG Process finished, return code=0
>>> 2015-10-01T14:45:44Z DEBUG stdout=
>>> 2015-10-01T14:45:44Z DEBUG stderr=
>>> 2015-10-01T14:45:44Z DEBUG Starting external process
>>> 2015-10-01T14:45:44Z DEBUG args='/bin/systemctl' 'is-active' 'dirsrv at INT-CCR-BUFFALO-EDU.service'
>>> 2015-10-01T14:45:44Z DEBUG Process finished, return code=0
>>> 2015-10-01T14:45:44Z DEBUG stdout=active
>>>
>>> 2015-10-01T14:45:44Z DEBUG stderr=
>>> 2015-10-01T14:45:44Z DEBUG wait_for_open_ports: localhost [389] timeout 300
>>> 2015-10-01T14:45:51Z DEBUG duration: 7 seconds
>>> 2015-10-01T14:45:51Z DEBUG Done.
>>> 2015-10-01T14:45:51Z DEBUG File "/usr/lib/python2.7/site-packages/ipapython/admintool.py", line 171, in execute
>>> return_value = self.run()
>>> File "/usr/lib/python2.7/site-packages/ipaserver/install/ipa_ldap_updater.py", line 151, in run
>>> raise admintool.ScriptError('IPA upgrade failed.', 1)
>>>
>>> 2015-10-01T14:45:51Z DEBUG The ipa-ldap-updater command failed, exception: ScriptError: IPA upgrade failed.
>>> 2015-10-01T14:45:51Z ERROR IPA upgrade failed.
>>> 2015-10-01T14:45:51Z DEBUG /usr/sbin/ipa-upgradeconfig was invoked with options: {'debug': False, 'quiet': True}
>>> 2015-10-01T14:45:51Z DEBUG IPA version 4.1.0-18.el7.centos.4
>>> 2015-10-01T14:45:51Z DEBUG Loading Index file from '/var/lib/ipa/sysrestore/sysrestore.index'
>>>
>>> ...
>>>
>>> 2015-10-01T14:48:37Z DEBUG The CA status is: running
>>> 2015-10-01T14:48:37Z INFO The ipa-upgradeconfig command was successful
>>>
>>>
>>> But from looking through the ipaupgrade.log it seems like the schema changes were in fact applied?
>>>
>> It looks like the DS has not been ready yet
>>
>> It started at:
>>
>> [01/Oct/2015:10:45:09 -0400] - slapd started. Listening on /var/run/slapd-INT-CCR-BUFFALO-EDU.socket for LDAPI requests
>>
>> But upgrade failed before:
>>
>> 2015-10-01T14:45:00Z ERROR Pre schema upgrade failed with [Errno 111] Connection refused
>>
>>
>> If there are no other errors listed, so other part of upgrade are
>> successful.
>> Pre-schema upgrade is done for DNS forward zones, but in case that this was
>> successfully done on master, dns forwardzones should be already updated.
>> This code is also removed in versions of IPA, so it should not cause issues
>> in future.
> Upgrading the 3rd replicate didn't fair so well either. I don't see any
> successful schema updates like I did in the previous 2 replicas in
> /var/log/ipaupgrade.log. Here's the errors from the 3rd replicate:
>
>
> 2015-10-01T17:20:06Z DEBUG duration: 0 seconds
> 2015-10-01T17:20:06Z DEBUG [5/10]: preparing server upgrade
> 2015-10-01T17:20:16Z ERROR Pre schema upgrade failed with [Errno 111] Connection refused
> 2015-10-01T17:20:16Z DEBUG Traceback (most recent call last):
> File "/usr/lib/python2.7/site-packages/ipaserver/install/upgradeinstance.py", line 128, in __pre_schema_upgrade
> ld = ldapupdate.LDAPUpdate(dm_password='', ldapi=True, live_run=self.live_run, plugins=True)
> File "/usr/lib/python2.7/site-packages/ipaserver/install/ldapupdate.py", line 220, in __init__
> self.create_connection()
> File "/usr/lib/python2.7/site-packages/ipaserver/install/ldapupdate.py", line 783, in create_connection
> dm_password=self.dm_password, pw_name=self.pw_name)
> File "/usr/lib/python2.7/site-packages/ipaserver/install/ldapupdate.py", line 65, in connect
> conn.do_external_bind(pw_name)
> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1761, in do_external_bind
> self.conn.sasl_interactive_bind_s, timeout, None, auth_tokens)
> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1747, in __bind_with_wait
> self.__wait_for_connection(timeout)
> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1733, in __wait_for_connection
> wait_for_open_socket(lurl.hostport, timeout)
> File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 1173, in wait_for_open_socket
> raise e
> error: [Errno 111] Connection refused
>
> 2015-10-01T17:20:16Z DEBUG duration: 10 seconds
> 2015-10-01T17:20:16Z DEBUG [6/10]: updating schema
> 2015-10-01T17:20:27Z DEBUG Traceback (most recent call last):
> File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 382, in start_creation
> run_step(full_msg, method)
> File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 372, in run_step
> method()
> File "/usr/lib/python2.7/site-packages/ipaserver/install/upgradeinstance.py", line 145, in __update_schema
> dm_password='', ldapi=True, live_run=self.live_run) or self.modified
> File "/usr/lib/python2.7/site-packages/ipaserver/install/schemaupdate.py", line 112, in update_schema
> fqdn=installutils.get_fqdn())
> File "/usr/lib/python2.7/site-packages/ipaserver/install/ldapupdate.py", line 65, in connect
> conn.do_external_bind(pw_name)
> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1761, in do_external_bind
> self.conn.sasl_interactive_bind_s, timeout, None, auth_tokens)
> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1747, in __bind_with_wait
> self.__wait_for_connection(timeout)
> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1733, in __wait_for_connection
> wait_for_open_socket(lurl.hostport, timeout)
> File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 1173, in wait_for_open_socket
> raise e
> error: [Errno 111] Connection refused
>
> 2015-10-01T17:20:27Z DEBUG [error] error: [Errno 111] Connection refused
> 2015-10-01T17:20:27Z DEBUG [cleanup]: stopping directory server
> 2015-10-01T17:20:27Z DEBUG Starting external process
> 2015-10-01T17:20:27Z DEBUG args='/bin/systemctl' 'stop' 'dirsrv at INT-CCR-BUFFALO-EDU.service'
> 2015-10-01T17:22:00Z DEBUG Process finished, return code=0
>
>
>
> 2015-10-01T17:22:00Z DEBUG [cleanup]: restoring configuration
> 2015-10-01T17:22:00Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
> 2015-10-01T17:22:00Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
> 2015-10-01T17:22:00Z DEBUG duration: 0 seconds
> 2015-10-01T17:22:00Z DEBUG File "/usr/lib/python2.7/site-packages/ipapython/admintool.py", line 171, in execute
> return_value = self.run()
> File "/usr/lib/python2.7/site-packages/ipaserver/install/ipa_ldap_updater.py", line 144, in run
> upgrade.create_instance()
> File "/usr/lib/python2.7/site-packages/ipaserver/install/upgradeinstance.py", line 93, in create_instance
> show_service_name=False)
> File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 382, in start_creation
> run_step(full_msg, method)
> File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 372, in run_step
> method()
> File "/usr/lib/python2.7/site-packages/ipaserver/install/upgradeinstance.py", line 145, in __update_schema
> dm_password='', ldapi=True, live_run=self.live_run) or self.modified
> File "/usr/lib/python2.7/site-packages/ipaserver/install/schemaupdate.py", line 112, in update_schema
> fqdn=installutils.get_fqdn())
> File "/usr/lib/python2.7/site-packages/ipaserver/install/ldapupdate.py", line 65, in connect
> conn.do_external_bind(pw_name)
> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1761, in do_external_bind
> self.conn.sasl_interactive_bind_s, timeout, None, auth_tokens)
> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1747, in __bind_with_wait
> self.__wait_for_connection(timeout)
> File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1733, in __wait_for_connection
> wait_for_open_socket(lurl.hostport, timeout)
> File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 1173, in wait_for_open_socket
> raise e
>
> 2015-10-01T17:22:00Z DEBUG The ipa-ldap-updater command failed, exception: error: [Errno 111] Connection refused
> 2015-10-01T17:22:00Z ERROR [Errno 111] Connection refused
> 2015-10-01T17:22:01Z DEBUG /usr/sbin/ipa-upgradeconfig was invoked with options: {'debug': False, 'quiet': True}
> 2015-10-01T17:22:01Z DEBUG IPA version 4.1.0-18.el7.centos.4
> 2015-10-01T17:22:01Z DEBUG Loading Index file from '/var/lib/ipa/sysrestore/sysrestore.index'
> 2015-10-01T17:22:01Z DEBUG importing all plugin modules in '/usr/lib/python2.7/site-packages/ipalib/plugins'...
> 2015-10-01T17:22:01Z DEBUG importing plugin module '/usr/lib/python2.7/site-packages/ipalib/plugins/aci.py'
>
>
> Then these errors are repeated:
>
> 2015-10-01T17:22:05Z DEBUG stderr=
> 2015-10-01T17:22:05Z DEBUG wait_for_open_ports: localhost [8080, 8443] timeout 300
> 2015-10-01T17:22:09Z DEBUG Waiting until the CA is running
> 2015-10-01T17:22:09Z DEBUG request 'https://srv-d13-40-02.int.ccr.buffalo.edu:443/ca/admin/ca/getStatus'
> 2015-10-01T17:22:09Z DEBUG request body ''
> 2015-10-01T17:22:17Z DEBUG request status 500
> 2015-10-01T17:22:17Z DEBUG request reason_phrase u'Internal Server Error'
> 2015-10-01T17:22:17Z DEBUG request headers {'content-length': '2923', 'content-language': 'en', 'server': 'Apache/2.4.6 (CentOS) mod_auth_kerb/5.4 mod_nss/2.4.6 NSS/3.16.2.3 Basic ECC mod_wsgi/3.4 Python/2.7.5', 'connection': 'close', 'date': 'Thu, 01 Oct 2015 17:22:09 GMT', 'content-type': 'text/html;charset=utf-8'}
> 2015-10-01T17:22:17Z DEBUG request body '<html><head><title>Apache Tomcat/7.0.54 - Error report</title><style><!--H1 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;} H2 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;} H3 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;} BODY {font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;} B {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;} P {font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;}A {color : black;}A.name {color : black;}HR {color : #525D76;}--></style> </head><body><h1>HTTP Status 500 - CS server is not ready to serve.</h1><HR size="1" noshade="noshade"><p><b>type</b> Exception report</p><p><b>message</b> <u>CS server is not ready to serve.</u></p><p><b>description</b> <u>The server encountered an internal error that prevented it from fulfilling this request.</u></p><p><b>exception</b> <pre>java.io.IOException: CS server is not ready to serve.\n\tcom.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:443)\n\tjavax.servlet.http.HttpServlet.service(HttpServlet.java:727)\n\tsun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\n\tsun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)\n\tsun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n\tjava.lang.reflect.Method.invoke(Method.java:606)\n\torg.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:277)\n\torg.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:274)\n\tjava.security.AccessController.doPrivileged(Native Method)\n\tjavax.security.auth.Subject.doAsPrivileged(Subject.java:536)\n\torg.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:309)\n\torg.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:169)\n\tjava.security.AccessController.doPrivileged(Native Method)\n\torg.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)\n\tsun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)\n\tsun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)\n\tsun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)\n\tjava.lang.reflect.Method.invoke(Method.java:606)\n\torg.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:277)\n\torg.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:274)\n\tjava.security.AccessController.doPrivileged(Native Method)\n\tjavax.security.auth.Subject.doAsPrivileged(Subject.java:536)\n\torg.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:309)\n\torg.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:249)\n</pre></p><p><b>note</b> <u>The full stack trace of the root cause is available in the Apache Tomcat/7.0.54 logs.</u></p><HR size="1" noshade="noshade"><h3>Apache Tomcat/7.0.54</h3></body></html>'
> 2015-10-01T17:22:17Z DEBUG The CA status is: check interrupted
> 2015-10-01T17:22:17Z DEBUG Waiting for CA to start...
> 2015-10-01T17:22:18Z DEBUG request 'https://srv-d13-40-02.int.ccr.buffalo.edu:443/ca/admin/ca/getStatus'
> 2015-10-01T17:22:18Z DEBUG request body ''
> 2015-10-01T17:22:18Z DEBUG request status 500
> 2015-10-01T17:22:18Z DEBUG request reason_phrase u'Internal Server Error'
> ....
> ....
>
> 2015-10-01T17:27:08Z DEBUG The CA status is: check interrupted
> 2015-10-01T17:27:08Z DEBUG Waiting for CA to start...
> 2015-10-01T17:27:09Z DEBUG File "/usr/lib/python2.7/site-packages/ipaserver/install/installutils.py", line 646, in run_script
> return_value = main_function()
>
> File "/usr/sbin/ipa-upgradeconfig", line 1376, in main
> upgrade_pki(ca, fstore)
>
> File "/usr/lib64/python2.7/contextlib.py", line 24, in __exit__
> self.gen.next()
>
> File "/usr/lib/python2.7/site-packages/ipaserver/install/installutils.py", line 888, in stopped_service
> service_obj.start(instance_name)
>
> File "/usr/lib/python2.7/site-packages/ipaplatform/redhat/services.py", line 203, in start
> self.wait_until_running()
>
> File "/usr/lib/python2.7/site-packages/ipaplatform/redhat/services.py", line 197, in wait_until_running
> raise RuntimeError('CA did not start in %ss' % timeout)
>
> 2015-10-01T17:27:09Z DEBUG The ipa-upgradeconfig command failed, exception: RuntimeError: CA did not start in 300.0s
This is interesting, can you check logs in /var/log/pki/pki-tomcat/ca/debug
>
>
> A few thoughts/concerns:
>
> 1. It looks like when the dirsrv is restarted as part of the upgrade it goes
> through thousands of iterations of:
>
> DSRetroclPlugin - delete_changerecord: could not delete change record 314605 (rc: 32)
>
> Before it finally becomes responsive and starts serving requests. This causes
> the ipa-upgrade to timeout. Should I have restarted the dirsrv first before
> performing the yum update?
You can try, but I'm not sure if this will help.
>
> 2. I had (incorrectly?) assumed this to be a very minor upgrade from
> 4.1.0-18.el7.centos.3 to 4.1.0-18.el7.centos.4. Is there expected to be major
> schema upgrades in minor point releases like this? Curious what the schema
> updates do?
It is minor upgrade, it contains just one fix which does not require
upgrade of LDAP data.
Schema upgrade checks if schema is up to date.
Schema is replicated, so if update on master was successful, schema is
also updated on replicas too.
>
> 3. All servers have been rebooted and seem to be up and running. Should I be
> concerned about the upgrade failures and replicating dirty (old) data? How can
> I verify the upgrades when OK?
You can try manually run ipa-ldap-updater --upgrade after yum upgrade.
Upgrade is idempotent, it should work.
But as I said before, it should work even if upgrade failed, because the
fix in minor version does not require schema/data upgrade.
>
> Thanks again for all the help.
>
> --Andrew
>
Martin
More information about the Freeipa-users
mailing list