Bug 845405 - ipa-replica-install httpd restart failed
ipa-replica-install httpd restart failed
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: ipa (Show other bugs)
6.2
i686 Linux
medium Severity medium
: rc
: ---
Assigned To: Rob Crittenden
Namita Soman
:
Depends On: 867467
Blocks:
  Show dependency treegraph
 
Reported: 2012-08-02 21:18 EDT by Scott Poore
Modified: 2015-05-19 09:42 EDT (History)
3 users (show)

See Also:
Fixed In Version: ipa-3.0.0-6.el6
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-02-21 04:16:58 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Scott Poore 2012-08-02 21:18:35 EDT
Description of problem:

During ipa-replica-install, sometimes httpd restart fails:

Configuring the web interface: Estimated time 1 minute
  [1/12]: disabling mod_ssl in httpd
  [2/12]: setting mod_nss port to 443
  [3/12]: setting mod_nss password file
  [4/12]: enabling mod_nss renegotiate
  [5/12]: adding URL rewriting rules
  [6/12]: configuring httpd
  [7/12]: setting up ssl
  [8/12]: publish CA cert
  [9/12]: creating a keytab for httpd
  [10/12]: configuring SELinux for httpd
  [11/12]: restarting httpd
  [12/12]: configuring httpd to start on boot
done configuring httpd.
creation of replica failed: Command '/sbin/service httpd restart ' returned non-zero exit status 1

I've seen this more than once now but, not yet able to reproduce.

Version-Release number of selected component (if applicable):
ipa-server-2.1.3-9.el6.i686
httpd-2.2.15-15.el6.i686

How reproducible:
Unknown

Steps to Reproduce:
1. <Set up RHEL6.2 IPA Master server>
2. On Master: ipa-replica-prepare -p $ADMINPW --ip-address=$SLAVE_IP $SLAVE_S.$DOMAIN
3. On Replica: sftp $MASTER:/var/lib/ipa/replica-info-$SLAVEFQDN.gpg /dev/shm
4. On Replica: ipa-replica-install -U --setup-dns --forwarder=$DNSFORWARD -w $ADMINPW -p $ADMINPW /dev/shm/replica-info-$SLAVEFQDN.gpg

Actual results:
Error from description above.  

Expected results:
No error.

Additional info:

From ipareplica-install.log:

2012-08-01 15:19:40,811 DEBUG stdout=pk12util: PKCS12 IMPORT SUCCESSFUL

2012-08-01 15:19:40,812 DEBUG stderr=
2012-08-01 15:19:52,763 DEBUG args=/sbin/service httpd restart
2012-08-01 15:19:52,770 DEBUG stdout=Stopping httpd: [  OK  ]
Starting httpd: [FAILED]

2012-08-01 15:19:52,770 DEBUG stderr=(98)Address already in use: make_sock: could not bind to address [::]:80
(98)Address already in use: make_sock: could not bind to address 0.0.0.0:80
no listening sockets available, shutting down
Unable to open logs

2012-08-01 15:19:52,799 DEBUG Command '/sbin/service httpd restart ' returned non-zero exit status 1
  File "/usr/sbin/ipa-replica-install", line 482, in <module>
    main()

  File "/usr/sbin/ipa-replica-install", line 447, in main
    ipaservices.knownservices.httpd.restart()

  File "/usr/lib/python2.6/site-packages/ipapython/platform/redhat.py", line 47, in restart
    ipautil.run(["/sbin/service", self.service_name, "restart", instance_name], capture_output=capture_output)

  File "/usr/lib/python2.6/site-packages/ipapython/ipautil.py", line 273, in run
    raise CalledProcessError(p.returncode, args)


From http/error_log:

[root@ipaqavmb httpd]# cat error_log
[Wed Aug 01 15:19:38 2012] [notice] SELinux policy enabled; httpd running as context unconfined_u:system_r:httpd_t:s0
[Wed Aug 01 15:19:38 2012] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Wed Aug 01 15:19:40 2012] [notice] Digest: generating secret for digest authentication ...
[Wed Aug 01 15:19:40 2012] [notice] Digest: done
[Wed Aug 01 15:19:40 2012] [warn] mod_wsgi: Compiled for Python/2.6.2.
[Wed Aug 01 15:19:40 2012] [warn] mod_wsgi: Runtime using Python/2.6.6.
[Wed Aug 01 15:19:41 2012] [notice] Apache/2.2.15 (Unix) DAV/2 mod_auth_kerb/5.4 mod_nss/2.2.15 NSS/3.12.9.0 mod_wsgi/3.2 Python/2.6.6 configured -- resuming normal operations
[Wed Aug 01 15:19:42 2012] [error] Exception KeyError: KeyError(-1216170160,) in <module 'threading' from '/usr/lib/python2.6/threading.pyc'> ignored
[Wed Aug 01 15:19:43 2012] [error] Exception KeyError: KeyError(-1216170160,) in <module 'threading' from '/usr/lib/python2.6/threading.pyc'> ignored
[Wed Aug 01 15:19:45 2012] [error] ipa: INFO: *** PROCESS START ***
[Wed Aug 01 15:19:45 2012] [error] ipa: INFO: *** PROCESS START ***



PS showed httpd processes still running like they were orphaned when service httpd restart ran the stop:
[root@ipaqavmb ~]# ps -ef|grep http
root     25610     1  0 16:35 ?        00:00:00 /usr/sbin/nss_pcache 983043 off /etc/httpd/alias
apache   25637     1  8 16:35 ?        00:00:02 /usr/sbin/httpd
apache   25639     1  7 16:35 ?        00:00:02 /usr/sbin/httpd
apache   25640     1  1 16:35 ?        00:00:00 /usr/sbin/httpd
apache   25642     1  1 16:35 ?        00:00:00 /usr/sbin/httpd
apache   25644     1  1 16:35 ?        00:00:00 /usr/sbin/httpd
apache   25645     1  1 16:35 ?        00:00:00 /usr/sbin/httpd
apache   25646     1  1 16:35 ?        00:00:00 /usr/sbin/httpd
apache   25647     1  1 16:35 ?        00:00:00 /usr/sbin/httpd
root     25936 22439  1 16:35 pts/6    00:00:00 grep http


So, it looks like a problem with the httpd stop from the init script?
Comment 4 Dmitri Pal 2012-08-03 16:49:38 EDT
Upstream ticket:
https://fedorahosted.org/freeipa/ticket/2965
Comment 5 Rob Crittenden 2012-08-10 10:05:46 EDT
Scott, does /var/run/httpd/httpd.pid exist?

I'm assuming that service httpd stop also fails?

Can you get the following:
- rpm -V httpd
- ls -l /etc/httpd
- ls -ldZ /var/run/httpd
- ls -ld /var/run/httpd
- grep -e ^ServerRoot -e ^PidFile /etc/httpd/conf/httpd.conf

I'm assuming that once a server gets into this state you can never get IPA installed on it?
Comment 6 Scott Poore 2012-08-21 11:06:32 EDT
httpd.pid's gone by the time I see this and can check but, I think it was used to kill the daemon/controller process.   That's what I'm guessing from all the orphans with PPID of 1 anyway.  Does that not make sense?


[root@ipaqavmd ~]# rpm -V httpd
[root@ipaqavmd ~]# echo $?
0
[root@ipaqavmd ~]# ls -l /etc/httpd
total 12
drwxr-xr-x. 2 root root 4096 Aug 21 09:49 alias
drwxr-xr-x. 2 root root 4096 Aug 21 09:49 conf
drwxr-xr-x. 2 root root 4096 Aug 21 09:49 conf.d
lrwxrwxrwx. 1 root root   19 Aug 21 09:40 logs -> ../../var/log/httpd
lrwxrwxrwx. 1 root root   27 Aug 21 09:40 modules -> ../../usr/lib/httpd/modules
lrwxrwxrwx. 1 root root   19 Aug 21 09:40 run -> ../../var/run/httpd
[root@ipaqavmd ~]# 
[root@ipaqavmd ~]# ls -ldZ /var/run/httpd
drwx--x---. root apache system_u:object_r:httpd_var_run_t:s0 /var/run/httpd
[root@ipaqavmd ~]# ls -ld /var/run/httpd
drwx--x---. 2 root apache 4096 Aug 21 09:50 /var/run/httpd
[root@ipaqavmd ~]# ls -ld /var/run/httpd/httpd.pid
ls: cannot access /var/run/httpd/httpd.pid: No such file or directory
[root@ipaqavmd ~]# grep -e ^ServerRoot -e ^PidFile /etc/httpd/conf/httpd.conf
ServerRoot "/etc/httpd"
PidFile run/httpd.pid

Also, it does look like I can uninstall/reinstall and it works.

on replica: ipa-server-install --uninstall -U
on master: ipa-replica-manage del $REPLICA --force
on master: ipa-replica-prepare -p $ADMINPW --ip-address=$SLAVE_IP $SLAVE_S.$DOMAIN
on replica: sftp $MASTER:/var/lib/ipa/replica-info-$SLAVEFQDN.gpg /dev/shm
on replica: ipa-replica-install -U --setup-dns --forwarder=$DNSFORWARD -w $ADMINPW -p $ADMINPW /dev/shm/replica-info-$SLAVEFQDN.gpg
Comment 7 Scott Poore 2012-09-25 18:22:45 EDT
Interestingly enough, I just saw this again on RHEL6.4 ipa-server-install (not replica)

Configuring the web interface: Estimated time 1 minute
  [1/14]: disabling mod_ssl in httpd
  [2/14]: setting mod_nss port to 443
  [3/14]: setting mod_nss password file
  [4/14]: enabling mod_nss renegotiate
  [5/14]: adding URL rewriting rules
  [6/14]: configuring httpd
  [7/14]: setting up ssl
  [8/14]: setting up browser autoconfig
  [9/14]: publish CA cert
  [10/14]: creating a keytab for httpd
  [11/14]: clean up any existing httpd ccache
  [12/14]: configuring SELinux for httpd
  [13/14]: restarting httpd
Unexpected error - see /var/log/ipaserver-install.log for details:
CalledProcessError: Command '/sbin/service httpd restart ' returned non-zero exit status 1
2012-09-25T22:09:23Z DEBUG   [13/14]: restarting httpd
2012-09-25T22:09:24Z DEBUG args=/sbin/service httpd status 
2012-09-25T22:09:24Z DEBUG stdout=httpd is stopped

2012-09-25T22:09:24Z DEBUG stderr=
2012-09-25T22:09:24Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
2012-09-25T22:09:37Z DEBUG args=/sbin/service httpd restart 
2012-09-25T22:09:37Z DEBUG stdout=Stopping httpd:          [FAILED]
Starting httpd:                                            [FAILED]

2012-09-25T22:09:37Z DEBUG stderr=[Tue Sep 25 17:09:36 2012] [warn] worker ajp://localhost:9447 already used by another worker
[Tue Sep 25 17:09:36 2012] [warn] worker ajp://localhost:9447 already used by another worker

2012-09-25T22:09:37Z INFO   File "/usr/lib/python2.6/site-packages/ipaserver/install/installutils.py", line 614, in run_script
    return_value = main_function()

  File "/usr/sbin/ipa-server-install", line 1033, in main
    http.create_instance(realm_name, host_name, domain_name, dm_password, autoconfig=True, self_signed_ca=options.selfsign, subject_base=options.subject, auto_redirect=options.ui_redirect)

  File "/usr/lib/python2.6/site-packages/ipaserver/install/httpinstance.py", line 102, in create_instance
    self.start_creation("Configuring the web interface", 60)

  File "/usr/lib/python2.6/site-packages/ipaserver/install/service.py", line 321, in start_creation
    method()

  File "/usr/lib/python2.6/site-packages/ipaserver/install/httpinstance.py", line 106, in __start
    self.restart()

  File "/usr/lib/python2.6/site-packages/ipaserver/install/service.py", line 267, in restart
    self.service.restart(instance_name, capture_output=capture_output, wait=wait)

  File "/usr/lib/python2.6/site-packages/ipapython/platform/redhat.py", line 74, in restart
    ipautil.run(["/sbin/service", self.service_name, "restart", instance_name], capture_output=capture_output)

  File "/usr/lib/python2.6/site-packages/ipapython/ipautil.py", line 307, in run
    raise CalledProcessError(p.returncode, args)

2012-09-25T22:09:37Z INFO The ipa-server-install command failed, exception: CalledProcessError: Command '/sbin/service httpd restart ' returned non-zero exit status 1
Comment 8 Martin Kosek 2012-10-17 10:56:40 EDT
I filed httpd Bug for RHEL 6.4 so we can get some response from httpd maintenance team: Bug 867467.
Comment 9 Martin Kosek 2012-10-18 03:12:49 EDT
Bug 867467 has been closed as NEXTRELEASE. You can check Joe Orton's response with reasoning there. Bottomline is that with sysV scripts cannot guarantee that httpd will always restart successfully when restarted in such a short notice. This should be fixed with systemd.

As for 6.4, I think this will instead lead to a patch to enforce a wait+fallback in case httpd restart fails.
Comment 10 Rob Crittenden 2012-10-19 14:12:11 EDT
Went with a wait+fallback in case httpd restart fails.

Fixed upstream.

master: 9126b18d8bbf7d8f0f8981deb84f80f2eaa27bfe

ipa-3-0: 5f95fbfad2729e59d67730d2d476befa4e0a2e02
Comment 13 Scott Poore 2012-12-05 19:25:30 EST
Verified. 

Version ::

ipa-server-3.0.0-10.el6.i686
ipa-client-3.0.0-10.el6.i686

Manual Test Results ::

I have not seen this re-occur on RHEL6.4 tests on x86_64 servers.  Testing here on i686:

[root@rhel6-5 ~]# ipa-replica-install -U --setup-dns --forwarder=$DNSFORWARD -w $ADMINPW -p $ADMINPW /dev/shm/replica-info-rhel6-5.testrelm.com.gpg 
Run connection check to master
Check connection from replica to remote master 'rhel6-1.testrelm.com':
   Directory Service: Unsecure port (389): OK
   Directory Service: Secure port (636): OK
   Kerberos KDC: TCP (88): OK
   Kerberos Kpasswd: TCP (464): OK
   HTTP Server: Unsecure port (80): OK
   HTTP Server: Secure port (443): OK

The following list of ports use UDP protocol and would need to be
checked manually:
   Kerberos KDC: UDP (88): SKIPPED
   Kerberos Kpasswd: UDP (464): SKIPPED

Connection from replica to master is OK.
Start listening on required ports for remote master check
Get credentials to log in to remote master
Execute check on remote master
Check connection from master to remote replica 'rhel6-5.testrelm.com':
   Directory Service: Unsecure port (389): OK
   Directory Service: Secure port (636): OK
   Kerberos KDC: TCP (88): OK
   Kerberos KDC: UDP (88): OK
   Kerberos Kpasswd: TCP (464): OK
   Kerberos Kpasswd: UDP (464): OK
   HTTP Server: Unsecure port (80): OK
   HTTP Server: Secure port (443): OK

Connection from master to replica is OK.

Connection check OK
Configuring NTP daemon (ntpd)
  [1/4]: stopping ntpd
  [2/4]: writing configuration
  [3/4]: configuring ntpd to start on boot
  [4/4]: starting ntpd
Done configuring NTP daemon (ntpd).
Configuring directory server (dirsrv): Estimated time 1 minute
  [1/31]: creating directory server user
  [2/31]: creating directory server instance
  [3/31]: adding default schema
  [4/31]: enabling memberof plugin
  [5/31]: enabling winsync plugin
  [6/31]: configuring replication version plugin
  [7/31]: enabling IPA enrollment plugin
  [8/31]: enabling ldapi
  [9/31]: disabling betxn plugins
  [10/31]: configuring uniqueness plugin
  [11/31]: configuring uuid plugin
  [12/31]: configuring modrdn plugin
  [13/31]: enabling entryUSN plugin
  [14/31]: configuring lockout plugin
  [15/31]: creating indices
  [16/31]: enabling referential integrity plugin
  [17/31]: configuring ssl for ds instance
  [18/31]: configuring certmap.conf
  [19/31]: configure autobind for root
  [20/31]: configure new location for managed entries
  [21/31]: restarting directory server
  [22/31]: setting up initial replication
Starting replication, please wait until this has completed.
Update in progress
Update in progress
Update in progress
Update in progress
Update succeeded
  [23/31]: adding replication acis
  [24/31]: setting Auto Member configuration
  [25/31]: enabling S4U2Proxy delegation
  [26/31]: initializing group membership
  [27/31]: adding master entry
  [28/31]: configuring Posix uid/gid generation
  [29/31]: enabling compatibility plugin
  [30/31]: tuning directory server
  [31/31]: configuring directory to start on boot
Done configuring directory server (dirsrv).
Configuring Kerberos KDC (krb5kdc): Estimated time 30 seconds
  [1/9]: adding sasl mappings to the directory
  [2/9]: writing stash file from DS
  [3/9]: configuring KDC
  [4/9]: creating a keytab for the directory
  [5/9]: creating a keytab for the machine
  [6/9]: adding the password extension to the directory
  [7/9]: enable GSSAPI for replication
  [8/9]: starting the KDC
  [9/9]: configuring KDC to start on boot
Done configuring Kerberos KDC (krb5kdc).
Configuring kadmin
  [1/2]: starting kadmin 
  [2/2]: configuring kadmin to start on boot
Done configuring kadmin.
Configuring ipa_memcached
  [1/2]: starting ipa_memcached 
  [2/2]: configuring ipa_memcached to start on boot
Done configuring ipa_memcached.
Configuring the web interface (httpd): Estimated time 1 minute
  [1/13]: disabling mod_ssl in httpd
  [2/13]: setting mod_nss port to 443
  [3/13]: setting mod_nss password file
  [4/13]: enabling mod_nss renegotiate
  [5/13]: adding URL rewriting rules
  [6/13]: configuring httpd
  [7/13]: setting up ssl
  [8/13]: publish CA cert
  [9/13]: creating a keytab for httpd
  [10/13]: clean up any existing httpd ccache
  [11/13]: configuring SELinux for httpd
  [12/13]: restarting httpd
  [13/13]: configuring httpd to start on boot
Done configuring the web interface (httpd).
Applying LDAP updates
Restarting the directory server
Restarting the KDC
Using reverse zone 122.168.192.in-addr.arpa.
Configuring DNS (named)
  [1/8]: adding NS record to the zone
  [2/8]: setting up reverse zone
  [3/8]: setting up our own record
  [4/8]: setting up kerberos principal
  [5/8]: setting up named.conf
  [6/8]: restarting named
  [7/8]: configuring named to start on boot
  [8/8]: changing resolv.conf to point to ourselves
Done configuring DNS (named).

Global DNS configuration in LDAP server is empty
You can use 'dnsconfig-mod' command to set global DNS options that
would override settings in local named.conf files

Restarting the web server

[root@rhel6-5 ~]# grep "Command '/sbin/service httpd restart ' returned non-zero exit status 1" /var/log/ipareplica-install.log

[root@rhel6-5 ~]#
Comment 15 errata-xmlrpc 2013-02-21 04:16:58 EST
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.

http://rhn.redhat.com/errata/RHSA-2013-0528.html

Note You need to log in before you can comment on or make changes to this bug.