Bug 1030081

Summary:	Packstack with ntp configuration hangs forever if ntpd service is already running
Product:	Red Hat OpenStack	Reporter:	Rami Vaknin <rvaknin>
Component:	openstack-packstack	Assignee:	Martin Magr <mmagr>
Status:	CLOSED ERRATA	QA Contact:	Nir Magnezi <nmagnezi>
Severity:	urgent	Docs Contact:
Priority:	unspecified
Version:	3.0	CC:	aortega, breeler, derekh, hateya, mmagr, oblaut, sclewis, yeylon
Target Milestone:	z3	Keywords:	Regression, ZStream
Target Release:	3.0
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	openstack-packstack-2013.1.1-0.37.dev705.el6ost	Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2013-11-18 15:20:00 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:

Description Rami Vaknin 2013-11-13 21:34:06 UTC

Version
=======
rhos 3.0.z on rhel6.5, puddle 2013-11-08.2

How reproducible
================
100% using my robot automation test

Description
===========
OpenStack installation using packstack hangs forever (I gave it almost a day to run), it happens when CONFIG_NTP_SERVERS are entered in the answer file and ntpd service is running before running packstack.
When stopping the ntpd service, packstack proceeds with OpenStack installation.


The processes running when packstack hangs
==========================================
# ps -efl | grep packstack | grep -v grep
4 S root      6838  6598  0  80   0 - 48544 poll_s 17:37 ?        00:00:10 /usr/bin/python /usr/bin/packstack --answer-file=/root/ANSWER_FILE
0 S root      7817  7816  0  80   0 - 25223 wait   17:38 ?        00:00:00 flock /var/tmp/packstack/c52c1a273c8e407492294298e2643f59/ps.lock puppet apply --modulepath /var/tmp/packstack/c52c1a273c8e407492294298e2643f59/modules /var/tmp/packstack/c52c1a273c8e407492294298e2643f59/manifests/10.35.160.29_ntpd.pp
0 S root      7818  7817  0  80   0 - 32531 wait   17:38 ?        00:00:00 /usr/bin/ruby /usr/bin/puppet apply --modulepath /var/tmp/packstack/c52c1a273c8e407492294298e2643f59/modules /var/tmp/packstack/c52c1a273c8e407492294298e2643f59/manifests/10.35.160.29_ntpd.pp
0 S root      7904  7818  0  80   0 - 13353 wait   17:38 ?        00:00:00 python /var/tmp/packstack/c52c1a273c8e407492294298e2643f59/modules/packstack/lib/facter/netns.py

From packstack's ntp-related file (stopping the ntpd service is missing)
========================================================================
Package['ntp'] -> File['ntp_config'] -> Exec['stop-ntpd'] -> Exec['ntpdate'] -> Service['ntpd']

More info
=========
# grep qa1 /etc/ntp.conf
<empty output>

# rpm -qa | grep ntp
ntpdate-4.2.6p5-1.el6.x86_64
ntp-4.2.6p5-1.el6.x86_64

# /etc/init.d/ntpd status
ntpd (pid  6048) is running...

# grep NTP /root/ANSWER_FILE 
# Comma separated list of NTP servers. Leave plain if Packstack
CONFIG_NTP_SERVERS=qa1.qa.lab.tlv.redhat.com


Note this old fixed bug, same cause, different result:
https://bugzilla.redhat.com/show_bug.cgi?id=905842

Comment 1 Rami Vaknin 2013-11-14 05:29:00 UTC

I'm not sure it has something to do with ntp anymore (generalizing the bug's title until further debug), it also stuck when packstack's answer file has an empty ntp configuration, here are the processes now:

# ps -efl |grep packstack | grep -v grep
4 S root      6847  6596  0  80   0 - 48512 poll_s 01:17 ?        00:00:25 /usr/bin/python /usr/bin/packstack --answer-file=/root/ANSWER_FILE
0 S root      8044  8043  0  80   0 - 25223 wait   01:19 ?        00:00:00 flock /var/tmp/packstack/6f39915d3b144204a4225b538100ff8b/ps.lock puppet apply --modulepath /var/tmp/packstack/6f39915d3b144204a4225b538100ff8b/modules /var/tmp/packstack/6f39915d3b144204a4225b538100ff8b/manifests/10.35.160.29_mysql.pp
0 S root      8045  8044  0  80   0 - 32567 wait   01:19 ?        00:00:01 /usr/bin/ruby /usr/bin/puppet apply --modulepath /var/tmp/packstack/6f39915d3b144204a4225b538100ff8b/modules /var/tmp/packstack/6f39915d3b144204a4225b538100ff8b/manifests/10.35.160.29_mysql.pp
0 S root      8059  8058  0  80   0 - 25223 flock_ 01:19 ?        00:00:00 flock /var/tmp/packstack/6f39915d3b144204a4225b538100ff8b/ps.lock puppet apply --modulepath /var/tmp/packstack/6f39915d3b144204a4225b538100ff8b/modules /var/tmp/packstack/6f39915d3b144204a4225b538100ff8b/manifests/10.35.160.29_qpid.pp
0 S root      8245  8045  0  80   0 - 13354 wait   01:19 ?        00:00:00 python /var/tmp/packstack/6f39915d3b144204a4225b538100ff8b/modules/packstack/lib/facter/netns.py

Could anyone can help on debugging it?

Comment 2 Rami Vaknin 2013-11-14 10:01:59 UTC

I ran packstack manually on Grizzly/2013-11-13.1 puddle with the "-d" switch, it seems like the ntpd manifests are not getting the ".finished" suffix hence the scp get fails on a "No such file or directory" forever.


2013-11-14 11:43:11::DEBUG::shell::61::root:: # ============ ssh : None ==========
2013-11-14 11:43:11::DEBUG::shell::75::root:: scp -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null root.160.27:/var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c/manifests/10.35.160.27_ntpd.pp.finished /var/tmp/packstack/20131114-111535-CKyPX7/manifests/10.35.160.27_ntpd.pp.log
2013-11-14 11:43:11::DEBUG::shell::78::root:: ============ STDOUT ==========
2013-11-14 11:43:11::DEBUG::shell::79::root:: 
2013-11-14 11:43:14::DEBUG::shell::61::root:: # ============ ssh : None ==========
2013-11-14 11:43:14::DEBUG::shell::75::root:: scp -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null root.160.23:/var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0/manifests/10.35.160.23_ntpd.pp.finished /var/tmp/packstack/20131114-111535-CKyPX7/manifests/10.35.160.23_ntpd.pp.log
2013-11-14 11:43:14::DEBUG::shell::78::root:: ============ STDOUT ==========
2013-11-14 11:43:14::DEBUG::shell::79::root:: 
2013-11-14 11:43:17::DEBUG::shell::61::root:: # ============ ssh : None ==========
2013-11-14 11:43:17::DEBUG::shell::75::root:: scp -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null root.160.25:/var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755/manifests/10.35.160.25_ntpd.pp.finished /var/tmp/packstack/20131114-111535-CKyPX7/manifests/10.35.160.25_ntpd.pp.log
2013-11-14 11:43:17::DEBUG::shell::78::root:: ============ STDOUT ==========
2013-11-14 11:43:17::DEBUG::shell::79::root:: 
2013-11-14 11:43:20::DEBUG::shell::61::root:: # ============ ssh : None ==========
2013-11-14 11:43:20::DEBUG::shell::75::root:: scp -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null root.160.29:/var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.finished /var/tmp/packstack/20131114-111535-CKyPX7/manifests/10.35.160.29_ntpd.pp.log
2013-11-14 11:43:21::DEBUG::shell::78::root:: ============ STDOUT ==========
2013-11-14 11:43:21::DEBUG::shell::79::root:: 


[root@puma10 ~]# scp -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null root.160.29:/var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.finished /var/tmp/packstack/20131114-111535-CKyPX7/manifests/10.35.160.29_ntpd.pp.log
Warning: Permanently added '10.35.160.29' (RSA) to the list of known hosts.
scp: /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.finished: No such file or directory
[root@puma10 ~]# ll /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.finished
ls: cannot access /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.finished: No such file or directory
[root@puma10 ~]# ll /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp
-rw-------. 1 root root 2662 Nov 14 11:16 /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp




Few lines before the infinite loop
==================================

2013-11-14 11:17:29::DEBUG::shell::61::root:: # ============ ssh : '10.35.160.29' ==========
2013-11-14 11:17:29::DEBUG::shell::75::root:: export FACTERLIB=$FACTERLIB:/var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/facts
touch /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.running
chmod 600 /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.running
export PACKSTACK_VAR_DIR=/var/tmp/packstack/3d6bd821590a420eb61db89532d7f666
( flock /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/ps.lock puppet apply --debug --modulepath /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/modules /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_
ntpd.pp > /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.running 2>&1 < /dev/null ; mv /var/tmp/packstack/3d6bd821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.running /var/tmp/packstack/3d6b
d821590a420eb61db89532d7f666/manifests/10.35.160.29_ntpd.pp.finished ) > /dev/null 2>&1 < /dev/null &
2013-11-14 11:17:29::DEBUG::shell::78::root:: ============ STDOUT ==========
2013-11-14 11:17:29::DEBUG::shell::79::root:: 
2013-11-14 11:17:29::DEBUG::shell::61::root:: # ============ ssh : '10.35.160.27' ==========
2013-11-14 11:17:29::DEBUG::shell::75::root:: export FACTERLIB=$FACTERLIB:/var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c/facts
touch /var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c/manifests/10.35.160.27_ntpd.pp.running
chmod 600 /var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c/manifests/10.35.160.27_ntpd.pp.running
export PACKSTACK_VAR_DIR=/var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c
( flock /var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c/ps.lock puppet apply --debug --modulepath /var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c/modules /var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c/manifests/10.35.160.27_
ntpd.pp > /var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c/manifests/10.35.160.27_ntpd.pp.running 2>&1 < /dev/null ; mv /var/tmp/packstack/51e89ab82d2f4ecbbeb0cdb4d45b561c/manifests/10.35.160.27_ntpd.pp.running /var/tmp/packstack/51e8
9ab82d2f4ecbbeb0cdb4d45b561c/manifests/10.35.160.27_ntpd.pp.finished ) > /dev/null 2>&1 < /dev/null &
2013-11-14 11:17:29::DEBUG::shell::78::root:: ============ STDOUT ==========
2013-11-14 11:17:29::DEBUG::shell::79::root:: 
2013-11-14 11:17:29::DEBUG::shell::61::root:: # ============ ssh : '10.35.160.23' ==========
2013-11-14 11:17:29::DEBUG::shell::75::root:: export FACTERLIB=$FACTERLIB:/var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0/facts
touch /var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0/manifests/10.35.160.23_ntpd.pp.running
chmod 600 /var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0/manifests/10.35.160.23_ntpd.pp.running
export PACKSTACK_VAR_DIR=/var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0
( flock /var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0/ps.lock puppet apply --debug --modulepath /var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0/modules /var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0/manifests/10.35.160.23_
ntpd.pp > /var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0/manifests/10.35.160.23_ntpd.pp.running 2>&1 < /dev/null ; mv /var/tmp/packstack/8a08bbaacb6d43e9b54c4eb6d9db1df0/manifests/10.35.160.23_ntpd.pp.running /var/tmp/packstack/8a08
bbaacb6d43e9b54c4eb6d9db1df0/manifests/10.35.160.23_ntpd.pp.finished ) > /dev/null 2>&1 < /dev/null &
2013-11-14 11:17:30::DEBUG::shell::78::root:: ============ STDOUT ==========
2013-11-14 11:17:30::DEBUG::shell::79::root:: 
2013-11-14 11:17:30::DEBUG::shell::61::root:: # ============ ssh : '10.35.160.25' ==========
2013-11-14 11:17:30::DEBUG::shell::75::root:: export FACTERLIB=$FACTERLIB:/var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755/facts
touch /var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755/manifests/10.35.160.25_ntpd.pp.running
chmod 600 /var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755/manifests/10.35.160.25_ntpd.pp.running
export PACKSTACK_VAR_DIR=/var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755
( flock /var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755/ps.lock puppet apply --debug --modulepath /var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755/modules /var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755/manifests/10.35.160.25_
ntpd.pp > /var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755/manifests/10.35.160.25_ntpd.pp.running 2>&1 < /dev/null ; mv /var/tmp/packstack/b40b8b52f5744a5abe155f222dbff755/manifests/10.35.160.25_ntpd.pp.running /var/tmp/packstack/b40b
8b52f5744a5abe155f222dbff755/manifests/10.35.160.25_ntpd.pp.finished ) > /dev/null 2>&1 < /dev/null &
2013-11-14 11:17:30::DEBUG::shell::78::root:: ============ STDOUT ==========
2013-11-14 11:17:30::DEBUG::shell::79::root::

Comment 3 Rami Vaknin 2013-11-14 10:11:30 UTC

Returning the bug title to the original one after making sure this is the issue here.

Comment 4 Martin Magr 2013-11-14 11:52:26 UTC

From following I see that it's netns.py what stopped packstack. We have to backport fix for that to grizzly branch:

0 S root      7904  7818  0  80   0 - 13353 wait   17:38 ?        00:00:00 python /var/tmp/packstack/c52c1a273c8e407492294298e2643f59/modules/packstack/lib/facter/netns.py

Comment 7 Rami Vaknin 2013-11-15 07:33:19 UTC

Verified on puddle Grizzly/2013-11-14.2, openstack-packstack-2013.1.1-0.37.dev705.el6ost, installation pass successfully when CONFIG_NTP_SERVERS is in use.

Comment 9 Lon Hohberger 2013-11-18 14:52:09 UTC

*** Bug 1029403 has been marked as a duplicate of this bug. ***

Comment 10 errata-xmlrpc 2013-11-18 15:20:00 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.

http://rhn.redhat.com/errata/RHBA-2013-1510.html