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....@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@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@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@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?
--
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
