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/[email protected]] 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'
'[email protected]'
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'
'[email protected]'
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'
'[email protected]'
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.
Martin
--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project
