Bug 1127766

Summary: staypuft with nova network deployment errors on trying to start nova-network service with 2 computes
Product: Red Hat OpenStack Reporter: Ami Jeain <ajeain>
Component: openstack-foreman-installerAssignee: Jason Guiditta <jguiditt>
Status: CLOSED DUPLICATE QA Contact: Ami Jeain <ajeain>
Severity: high Docs Contact:
Priority: unspecified    
Version: 5.0 (RHEL 7)CC: jguiditt, mburns, morazi, rhos-maint, sclewis, yeylon
Target Milestone: async   
Target Release: Installer   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-08-21 13:21:26 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:

Description Ami Jeain 2014-08-07 13:59:31 UTC 
Description of problem:


Version-Release number of selected component (if applicable):

# rpm -qa |grep osp
rhel-osp-installer-0.1.6-5.el6ost.noarch

How reproducible:
 2 out of 2 tries

Steps to Reproduce:
1. deploy a nova network staypuft deployment with 1 controller + 2 computes
2. at around 80%, the puppet gets to a dead lock, and if you try to run strace on the puppet process, it is in wait status, and if u try and debug it using 'journalctl -u puppet', you get the following errors:
3.

Actual results:

# journalctl -u puppet
-- Logs begin at Thu 2014-08-07 12:34:41 UTC, end at Thu 2014-08-07 13:27:30 UTC. --
Aug 07 12:35:01 maca25400868097.example.com systemd[1]: Starting Puppet agent...
Aug 07 12:35:01 maca25400868097.example.com systemd[1]: Started Puppet agent.
Aug 07 12:35:07 maca25400868097.example.com puppet-agent[1565]: Starting Puppet client version 3.6.2
Aug 07 12:35:30 maca25400868097.example.com puppet-agent[4411]: The package type's allow_virtual parameter will be changing its default value from false to true in a future release. If you do not w
Aug 07 12:35:30 maca25400868097.example.com puppet-agent[4411]: (at /usr/share/ruby/vendor_ruby/puppet/type.rb:816:in `set_default')
Aug 07 12:35:37 maca25400868097.example.com yum[8452]: Installed: MySQL-python-1.2.3-11.el7.x86_64
Aug 07 12:35:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Mysql::Python/Package[python-mysqldb]/ensure) created
Aug 07 12:35:56 maca25400868097.example.com yum[10858]: Installed: python-six-1.6.1-1.el7.noarch
Aug 07 12:35:57 maca25400868097.example.com yum[10858]: Installed: python-webob-1.2.3-6.el7.noarch
Aug 07 12:35:57 maca25400868097.example.com yum[10858]: Installed: python-prettytable-0.7.2-1.el7.noarch
Aug 07 12:35:58 maca25400868097.example.com yum[10858]: Installed: python-iso8601-0.1.8-1.el7ost.noarch
Aug 07 12:36:01 maca25400868097.example.com yum[10858]: Installed: python-sqlalchemy-0.8.4-1.el7ost.x86_64
Aug 07 12:36:02 maca25400868097.example.com yum[10858]: Installed: python-babel-0.9.6-8.el7.noarch
Aug 07 12:36:03 maca25400868097.example.com yum[10858]: Installed: 1:python-oslo-config-1.2.1-1.el7ost.noarch
Aug 07 12:36:03 maca25400868097.example.com yum[10858]: Installed: python-tempita-0.5.1-6.el7.noarch
Aug 07 12:36:04 maca25400868097.example.com yum[10858]: Installed: python-greenlet-0.4.2-1.el7ost.x86_64
Aug 07 12:36:04 maca25400868097.example.com yum[10858]: Installed: python-anyjson-0.3.3-3.el7ost.noarch
Aug 07 12:36:06 maca25400868097.example.com yum[10858]: Installed: 1:net-snmp-libs-5.7.2-18.el7.x86_64
Aug 07 12:36:07 maca25400868097.example.com yum[10858]: Installed: python-simplegeneric-0.8-7.el7ost.noarch
Aug 07 12:36:07 maca25400868097.example.com yum[10858]: Installed: lm_sensors-libs-3.3.4-10.el7.x86_64
Aug 07 12:36:08 maca25400868097.example.com yum[10858]: Installed: python-keyring-3.6-1.el7ost.noarch
Aug 07 12:36:08 maca25400868097.example.com yum[10858]: Installed: yajl-2.0.4-4.el7.x86_64
Aug 07 12:36:09 maca25400868097.example.com yum[10858]: Installed: python-eventlet-0.14.0-1.el7ost.noarch
Aug 07 12:36:11 maca25400868097.example.com yum[10858]: Installed: python-paste-1.7.5.1-9.20111221hg1498.el7.noarch
Aug 07 12:36:12 maca25400868097.example.com yum[10858]: Installed: python-beaker-1.5.4-10.el7.noarch
Aug 07 12:36:13 maca25400868097.example.com yum[10858]: Installed: python-migrate-0.8.2-2.el7ost.noarch
Aug 07 12:36:14 maca25400868097.example.com yum[10858]: Installed: python-webtest-1.3.4-6.el7.noarch
Aug 07 12:36:15 maca25400868097.example.com yum[10858]: Installed: python-singledispatch-3.4.0.2-2.el7ost.noarch
Aug 07 12:36:15 maca25400868097.example.com yum[10858]: Installed: python-urllib3-1.5-8.el7.noarch
Aug 07 12:36:16 maca25400868097.example.com yum[10858]: Installed: 1:perl-parent-0.225-244.el7.noarch
Aug 07 12:36:16 maca25400868097.example.com yum[10858]: Installed: perl-HTTP-Tiny-0.033-3.el7.noarch
Aug 07 12:36:17 maca25400868097.example.com yum[10858]: Installed: perl-podlators-2.5.1-3.el7.noarch
Aug 07 12:36:18 maca25400868097.example.com yum[10858]: Installed: perl-Pod-Perldoc-3.20-4.el7.noarch
Aug 07 12:36:18 maca25400868097.example.com yum[10858]: Installed: 1:perl-Pod-Escapes-1.04-283.el7.noarch
Aug 07 12:36:18 maca25400868097.example.com yum[10858]: Installed: perl-Text-ParseWords-3.29-4.el7.noarch
Aug 07 12:36:20 maca25400868097.example.com yum[10858]: Installed: perl-Encode-2.51-7.el7.x86_64
Aug 07 12:36:20 maca25400868097.example.com yum[10858]: Installed: perl-Pod-Usage-1.63-3.el7.noarch
Aug 07 12:36:20 maca25400868097.example.com yum[10858]: Installed: 4:perl-libs-5.16.3-283.el7.x86_64
Aug 07 12:36:20 maca25400868097.example.com yum[10858]: Installed: 4:perl-macros-5.16.3-283.el7.x86_64
Aug 07 12:36:21 maca25400868097.example.com yum[10858]: Installed: perl-Socket-2.010-3.el7.x86_64
Aug 07 12:36:21 maca25400868097.example.com yum[10858]: Installed: perl-threads-1.87-4.el7.x86_64
Aug 07 12:36:21 maca25400868097.example.com yum[10858]: Installed: perl-Storable-2.45-3.el7.x86_64
...skipping...
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer/Ceilometer_config[DEFAULT/verbose]/ensure) created
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova/Nova_config[DEFAULT/lock_path]/ensure) created
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer/Ceilometer_config[DEFAULT/rabbit_password]/ensure) created
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova/Nova_config[DEFAULT/service_down_time]/ensure) created
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Compute::Libvirt/Nova_config[DEFAULT/vncserver_listen]/ensure) created
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer/Ceilometer_config[DEFAULT/rabbit_use_ssl]/ensure) created
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova/Nova_config[DEFAULT/notification_topics]/ensure) created
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Quickstack::Nova_network::Compute/Nova_config[DEFAULT/network_host]/ensure) created
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova/Nova_config[DEFAULT/auth_strategy]/ensure) created
Aug 07 12:44:39 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Compute::Libvirt/Nova_config[DEFAULT/compute_driver]/ensure) created
Aug 07 12:44:40 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Quickstack::Openstack_common/Service[firewalld]/enable) enable changed 'true' to 'false'
Aug 07 12:44:40 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova/Nova_config[DEFAULT/rootwrap_config]/ensure) created
Aug 07 12:44:40 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer::Agent::Auth/Ceilometer_config[service_credentials/os_password]/ensure) created
Aug 07 12:44:40 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova/Nova_config[DEFAULT/rpc_backend]/ensure) created
Aug 07 12:44:40 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Network::Flatdhcp/Nova_config[DEFAULT/fixed_range]/ensure) created
Aug 07 12:44:40 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova/Nova_config[DEFAULT/use_syslog]/ensure) created
Aug 07 12:44:40 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Network::Flatdhcp/Nova_config[DEFAULT/dhcp_domain]/ensure) created
Aug 07 12:44:40 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Network/Nova_config[DEFAULT/floating_range]/ensure) created
Aug 07 12:44:40 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Network/Sysctl::Value[net.ipv4.ip_forward]/Sysctl[net.ipv4.ip_forward]/ensure) created
Aug 07 12:44:43 maca25400868097.example.com yum[11894]: Installed: openstack-nova-network-2014.1.1-4.el7ost.noarch
Aug 07 12:44:45 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Network/Nova::Generic_service[network]/Package[nova-network]/ensure) created
Aug 07 12:44:45 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer/Ceilometer_config[DEFAULT/debug]/ensure) created
Aug 07 12:44:45 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Network/Sysctl::Value[net.ipv4.ip_forward]/Exec[exec_sysctl_net.ipv4.ip_forward]) Triggered 'refresh' from 1 even
Aug 07 12:44:45 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Compute::Libvirt/Service[messagebus]/ensure) ensure changed 'stopped' to 'running'
Aug 07 12:44:45 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Compute::Libvirt/Service[libvirt]/ensure) ensure changed 'stopped' to 'running'
Aug 07 12:44:45 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer/File[/etc/ceilometer/ceilometer.conf]/owner) owner changed 'root' to 'ceilometer'
Aug 07 12:44:47 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Quickstack::Tuned::Virtual_host/Exec[tuned-virtual-host]/returns) executed successfully
Aug 07 12:44:47 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer/Ceilometer_config[publisher/metering_secret]/ensure) created
Aug 07 12:44:47 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer/Ceilometer_config[DEFAULT/rabbit_port]/ensure) created
Aug 07 12:44:47 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer::Agent::Compute/Service[ceilometer-agent-compute]/ensure) ensure changed 'stopped' to 'running'
Aug 07 12:44:47 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Network::Flatdhcp/Nova_config[DEFAULT/flat_injected]/ensure) created
Aug 07 12:44:47 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova/File[/etc/nova/nova.conf]/owner) owner changed 'root' to 'nova'
Aug 07 12:44:47 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer::Agent::Compute/File_line_after[nova-notification-driver-common]/ensure) created
Aug 07 13:25:58 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova/Exec[post-nova_config]) Triggered 'refresh' from 49 events
Aug 07 13:26:00 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Quickstack::Nova_network::Compute/Nova::Generic_service[metadata-api]/Service[nova-metadata-api]/ensure) ensure changed
Aug 07 13:26:01 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Ceilometer::Agent::Compute/File_line_after[nova-notification-driver-ceilometer]/ensure) created
Aug 07 13:26:02 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Compute/Nova::Generic_service[compute]/Service[nova-compute]/ensure) ensure changed 'stopped' to 'running'
Aug 07 13:26:03 maca25400868097.example.com puppet-agent[4411]: Could not start Service[nova-network]: Execution of '/usr/bin/systemctl start openstack-nova-network' returned :
Aug 07 13:26:03 maca25400868097.example.com puppet-agent[4411]: Wrapped exception:
Aug 07 13:26:03 maca25400868097.example.com puppet-agent[4411]: Execution of '/usr/bin/systemctl start openstack-nova-network' returned :
Aug 07 13:26:03 maca25400868097.example.com puppet-agent[4411]: (/Stage[main]/Nova::Network/Nova::Generic_service[network]/Service[nova-network]/ensure) change from stopped to running failed: Could
Aug 07 13:26:03 maca25400868097.example.com puppet-agent[1565]: Caught TERM; calling stop
Aug 07 13:26:03 maca25400868097.example.com puppet-agent[4411]: Caught TERM; calling stop

Expected results:

nova network service starts fine and the deployment completes to the end
Additional info:
Comment 3 Mike Orazi 2014-08-20 12:32:46 UTC 
I believe this is a known issue where a race condition exists in nova compute node db creation.  It only occurs on the first two nodes.  After the db has been established, I believe as many simultaneous compute nodes as desired can be added without hitting this issue.
Comment 7 Jason Guiditta 2014-08-20 15:49:04 UTC 
I believe this is a dup of https://bugzilla.redhat.com/show_bug.cgi?id=1126072, though the subjects dont immediately give that indication
Comment 8 Mike Burns 2014-08-21 13:21:26 UTC 

*** This bug has been marked as a duplicate of bug 1126072 ***