Bug 1131187

Summary:	ipa-ldap-upgrade should restore Directory Server settings when upgrade fails
Product:	Red Hat Enterprise Linux 7	Reporter:	Martin Kosek <mkosek>
Component:	ipa	Assignee:	Martin Kosek <mkosek>
Status:	CLOSED ERRATA	QA Contact:	Namita Soman <nsoman>
Severity:	unspecified	Docs Contact:
Priority:	medium
Version:	7.0	CC:	jgalipea, mkosek, nhosoi, nkinder, pviktori, rcritten, rmeggins, spoore, sramling, tlavigne
Target Milestone:	rc
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	ipa-4.1.0-0.1.alpha1.el7	Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:	1130252	Environment:
Last Closed:	2015-03-05 10:13:22 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:
Bug Depends On:	1130252
Bug Blocks:

Description Martin Kosek 2014-08-18 15:55:04 UTC

+++ This bug was initially created as a clone of Bug #1130252 +++

Description of problem:

Upgrading a RHEL6.5 server to 6.6 version of IPA (and components) results in IPA not running.  I also see named failure during upgrade output:

  Updating   : ipa-server-3.0.0-42.el6.x86_64                                                    26/45 
Failed to restart named: Command '/sbin/service named restart ' returned non-zero exit status 7
  Updating   : ipa-server-selinux-3.0.0-42.el6.x86_64                                            27/45 

Some digging through ipaupgrade.log shows failures to stop dirsrv as if it's already stopped:

2014-08-14T16:14:13Z DEBUG Upgrading IPA:
2014-08-14T16:14:13Z DEBUG   [1/8]: stopping directory server
2014-08-14T16:14:13Z DEBUG args=/sbin/service dirsrv stop TESTRELM-TEST
2014-08-14T16:14:13Z DEBUG stdout=Shutting down dirsrv: 
    TESTRELM-TEST... server already stopped[FAILED]
  *** Error: 1 instance(s) unsuccessfully stopped[FAILED]

Then looking at messages for yum update and named messages shows:

Aug 14 11:12:06 rhel6-1 yum[14053]: Updated: 389-ds-base-libs-1.2.11.15-39.el6.x86_64
Aug 14 11:12:12 rhel6-1 named[4089]: LDAP error: Can't contact LDAP server
Aug 14 11:12:12 rhel6-1 named[4089]: connection to the LDAP server was lost
Aug 14 11:12:12 rhel6-1 named[4089]: bind to LDAP server failed: Can't contact LDAP server
Aug 14 11:12:12 rhel6-1 named[4089]: ldap_psearch_watcher failed to handle LDAP connection error. Recon
nection in 60s
Aug 14 11:12:25 rhel6-1 yum[14053]: Updated: 389-ds-base-1.2.11.15-39.el6.x86_64

And in dirsrv errors log I can see that it was stopped but I don't see anything about it being started:

[14/Aug/2014:11:12:09 -0500] - slapd shutting down - signaling operation threads
[14/Aug/2014:11:12:09 -0500] - slapd shutting down - closing down internal subsystems and plugins
[14/Aug/2014:11:12:09 -0500] - Waiting for 4 database threads to stop
[14/Aug/2014:11:12:09 -0500] - All database threads now stopped
[14/Aug/2014:11:12:09 -0500] - slapd stopped.


Version-Release number of selected component (if applicable):
389-ds-base-1.2.11.15-39.el6.x86_64

How reproducible:
always

Steps to Reproduce:
1.  on RHEL6.5 host, ipa-server-install # with dns configured
2.  setup RHEL6.6 yum repo configs
3.  yum update 'ipa*' sssd -y

Actual results:
dirsrv (and thus ipa) not running after upgrade.

Expected results:
everything running.

Additional info:

...
--- Additional comment from Scott Poore on 2014-08-14 22:04:44 EDT ---

If I upgrade openldap, I now get this:

[root@rhel6-2 slapd-TEST-QE]# service dirsrv restart
Shutting down dirsrv: 
    PKI-IPA...                                             [  OK  ]
    TEST-QE...                                             [  OK  ]
Starting dirsrv: 
    PKI-IPA...                                             [  OK  ]
    TEST-QE...[14/Aug/2014:17:17:50 -0500] - Information: Non-Secure Port Disabled
                                                           [  OK  ]

And I can't see the 389 port open now:

[root@rhel6-2 dirsrv]# netstat -taupne |grep 389
tcp        0      0 :::7389                     :::*                        LISTEN      0          56704      17958/ns-slapd      


I still can't start ipa.  How can I track down why slapd isn't starting on port 389?  Is there a logging level I should use?

I'm changing component here to 389-ds-base since that seems to be the main piece here.

...
--- Additional comment from Rob Crittenden on 2014-08-18 09:43:08 EDT ---

I wonder if IPA should have a clone of this bug. There should be a failsafe in the IPA updater such that it ALWAYS resets the listeners back to their initial values (so 389 and security on)

--- Additional comment from Martin Kosek on 2014-08-18 11:51:26 EDT ---

Actually, this is a very good idea. We want to make upgrade process smoother. I will clone the Bugzilla.

Comment 1 Martin Kosek 2014-08-18 16:00:41 UTC

Upstream ticket:
https://fedorahosted.org/freeipa/ticket/4499

Comment 3 Martin Kosek 2014-09-25 11:25:13 UTC

Fixed upstream
master:
https://fedorahosted.org/freeipa/changeset/9a188607fcf68721fc8c38c3c73ee02cac76b58a
ipa-4-1:
https://fedorahosted.org/freeipa/changeset/b333e7adc98ff7c5335fbc7ce1bde5b9dfb3f5ef

Comment 4 Martin Kosek 2014-09-26 14:57:45 UTC

Additional fix to not display error in SystemError(0) case.


master:
https://fedorahosted.org/freeipa/changeset/f86618623964f9a97244ce08117c575b200a34af
ipa-4-1:
https://fedorahosted.org/freeipa/changeset/540f4166e45752ae74f652f66eec9b92413a5d1e

Comment 6 Scott Poore 2015-01-13 16:17:35 UTC

Is this change just a change in error output?

How can I test this?  Any thoughts on how to force an upgrade failure?

Comment 7 Martin Kosek 2015-01-14 13:36:38 UTC

I personally just run [CTRL+C] combo during ipa-ldap-upgrade or did a direct update of the script to break. With the updated code, you should see that ipa-ldap-upgrade catches the failure and cleans up.

CCing Petr Viktorin, maybe he had a more sophisticated reproduction method.

Comment 8 Scott Poore 2015-01-15 19:41:43 UTC

Verified.

Version ::

---> Package ipa-server.x86_64 0:3.3.3-28.el7 will be updated
---> Package ipa-server.x86_64 0:4.1.0-13.el7 will be an update


Results ::

using CTRL+C during yum update, I see it error, traceback, and cleanup in ipaupgade.log:

2015-01-15T19:33:06Z 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 167, in update_schema
    conn.update_entry(schema_entry)
  File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1628, in update_entry
    self.conn.modify_s(entry.dn, modlist)
  File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 560, in modify_s
    return self.conn.modify_s(dn, modlist)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 357, in modify_s
    return self.result(msgid,all=1,timeout=self.timeout)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 458, in result
    resp_type, resp_data, resp_msgid = self.result2(msgid,all,timeout)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 462, in result2
    resp_type, resp_data, resp_msgid, resp_ctrls = self.result3(msgid,all,timeout)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 469, in result3
    resp_ctrl_classes=resp_ctrl_classes
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 476, in result4
    ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 99, in _ldap_call
    result = func(*args,**kwargs)
KeyboardInterrupt
2015-01-15T19:33:06Z DEBUG   [error] KeyboardInterrupt: 
2015-01-15T19:33:06Z DEBUG   [cleanup]: stopping directory server
2015-01-15T19:33:06Z DEBUG Starting external process
2015-01-15T19:33:06Z DEBUG args='/bin/systemctl' 'stop' 'dirsrv'
2015-01-15T19:33:08Z DEBUG Process finished, return code=0
2015-01-15T19:33:08Z DEBUG stdout=
2015-01-15T19:33:08Z DEBUG stderr=
2015-01-15T19:33:08Z DEBUG   duration: 1 seconds
2015-01-15T19:33:08Z DEBUG   [cleanup]: restoring configuration
2015-01-15T19:33:08Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
2015-01-15T19:33:08Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
2015-01-15T19:33:08Z DEBUG   duration: 0 seconds
2015-01-15T19:33:08Z 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 167, in update_schema
    conn.update_entry(schema_entry)
  File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1628, in update_entry
    self.conn.modify_s(entry.dn, modlist)
  File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 560, in modify_s
    return self.conn.modify_s(dn, modlist)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 357, in modify_s
    return self.result(msgid,all=1,timeout=self.timeout)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 458, in result
    resp_type, resp_data, resp_msgid = self.result2(msgid,all,timeout)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 462, in result2
    resp_type, resp_data, resp_msgid, resp_ctrls = self.result3(msgid,all,timeout)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 469, in result3
    resp_ctrl_classes=resp_ctrl_classes
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 476, in result4
    ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
  File "/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 99, in _ldap_call
    result = func(*args,**kwargs)

2015-01-15T19:33:08Z DEBUG The ipa-ldap-updater command failed, exception: KeyboardInterrupt: 
2015-01-15T19:33:08Z ERROR Cancelled.

Comment 9 Scott Poore 2015-01-15 19:45:51 UTC

Petr,

Do you have a better way to test this?  Something I might be able to use in test automation?

Thanks,
Scott

Comment 10 Petr Viktorin (pviktori) 2015-01-16 08:59:11 UTC

Unfortunately I don't. This is handling of unknown errors, if an error was known it would be fixed elsewhere.

I tested the same way as Martin, Ctrl+C or modifying the code itself.

Comment 12 errata-xmlrpc 2015-03-05 10:13:22 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHSA-2015-0442.html