Haproxy_backend_status[mysql]) Could not evaluate: Could not get CSV after 600 seconds!

[M Lebel]

Steps to reproduce:

Mos 9.0

1. Create cluster
2. Add 3 nodes with controller role
3. Add 3 node with compute role
4. Add 3 nodes for ceph osd
5. Run network verification
6. Deploy the cluster

Expected result:
Deploy pass

Actual result:
Deploy failed.

I deployed this exact environment a month or two ago without any issues. Then, I needed to restart from scratch.

I have tried playing with all the settings. I even tried replacing one system which was the one the deployment always seem to fail on. Still no luck.

The puppet log (with way more down the list):

2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/bin/puppet:8:in `<main>'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/util/command_line.rb:92:in `execute'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/util/command_line.rb:146:in `run'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/application.rb:381:in `run'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:496:in `exit_on_fail'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/application.rb:381:in `block in run'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/application.rb:507:in `plugin_hook'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/application.rb:381:in `block (2 levels) in run'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:159:in `run_command'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:198:in `main'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet.rb:246:in `override'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/context.rb:64:in `override'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:236:in `block in main'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:302:in `apply_catalog'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:133:in `run'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet.rb:246:in `override'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/context.rb:64:in `override'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:134:in `block in run'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:227:in `run_internal'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:119:in `apply_catalog'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:160:in `benchmark'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/1.9.1/benchmark.rb:295:in `realtime'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:161:in `block in benchmark'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:120:in `block in apply_catalog'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:168:in `apply'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/transaction/report.rb:112:in `as_logging_destination'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/util/log.rb:149:in `with_destination'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:169:in `block in apply'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:138:in `evaluate'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:147:in `block in evaluate'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:334:in `thinmark'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/1.9.1/benchmark.rb:295:in `realtime'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:335:in `block in thinmark'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:147:in `block (2 levels) in evaluate'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:147:in `call'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:217:in `eval_resource'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:204:in `apply'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:19:in `evaluate'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:236:in `from_resource'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/type.rb:1076:in `retrieve_resource'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/type.rb:1048:in `retrieve'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/property.rb:471:in `retrieve'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /etc/puppet/modules/haproxy/lib/puppet/provider/haproxy_backend_status/haproxy.rb:52:in `ensure'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /etc/puppet/modules/haproxy/lib/puppet/provider/haproxy_backend_status/haproxy.rb:84:in `status'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /etc/puppet/modules/haproxy/lib/puppet/provider/haproxy_backend_status/haproxy.rb:30:in `stats'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /etc/puppet/modules/haproxy/lib/puppet/provider/haproxy_backend_status/haproxy.rb:22:in `csv'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) /usr/lib/ruby/vendor_ruby/puppet/util/errors.rb:106:in `fail'
2016-09-09 21:38:14 ERR (/Stage[main]/Osnailyfacter::Database::Database_backend_wait/Osnailyfacter::Wait_for_backend[mysql]/Haproxy_backend_status[mysql]) Could not evaluate: Could not get CSV after 600 seconds!

2016-09-09 21:28:12 NOTICE Compiled catalog for node-46.example.com in environment production in 2.46 seconds
2016-09-09 21:28:10 NOTICE (Scope(Class[Osnailyfacter::Database::Database])) MODULAR: database/database.pp
2016-09-09 21:28:06 NOTICE Finished catalog run in 602.27 seconds

Anyone have any clue? is this a bug? I searched hi and low on the forums but I didn't find much that helps me out here.

Impact: Can't deploy the openstack cluster.

Let me know if you need more information.

Thank you

[M Lebel (mlebelj23all)]

After trying again and more research, I ended up finding https://bugs.launchpad.net/fuel/+bug/1592842 which i'm thinking is related?

From that, I ended up finding the following in the astute logs:

[1439] Cluster[]: Stop deployment by internal reason
[1439] Cluster[]: Fault tolerance exceeded the stop conditions [{"fault_tolerance"=>-1, "name"=>"primary-controller", "node_ids"=>[], "failed_node_ids"=>["46"]}]
[1439] Retrying to run puppet for following error nodes: 46
[1439] Retrying to run puppet for following error nodes: 46

[M Lebel (mlebelj23all)]

Update:

I finally managed to sort of deploy this environment.
As a result, I nailed this one down to the SSL/TLS certificate. Maybe I didn't understand something.

If I reset the environment(this was apparently required), set the hostname, choose self-signed option. The cloud deploy's fine.
As soon as I go to add my own pem file, deployment breaks.

I use a Class 1 Certificate from StartSSL.com and I believe it's working correctly except for:

2016-09-14 01:15:34 NOTICE Finished catalog run in 25.32 seconds
2016-09-14 01:15:34 WARNING (/Stage[main]/Openstack_tasks::Openstack_network::Networks/Neutron_subnet[admin_floating_net__subnet]) Skipping because of failed dependencies
2016-09-14 01:15:34 NOTICE (/Stage[main]/Openstack_tasks::Openstack_network::Networks/Neutron_subnet[admin_floating_net__subnet]) Dependency Neutron_network[admin_floating_net] has failures: true
2016-09-14 01:15:34 WARNING (/Stage[main]/Openstack_tasks::Openstack_network::Networks/Neutron_subnet[admin_internal_net__subnet]) Skipping because of failed dependencies
2016-09-14 01:15:34 NOTICE (/Stage[main]/Openstack_tasks::Openstack_network::Networks/Neutron_subnet[admin_internal_net__subnet]) Dependency Neutron_network[admin_internal_net] has failures: true
2016-09-14 01:15:34 ERR /usr/bin/puppet:8:in `<main>'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/util/command_line.rb:92:in `execute'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/util/command_line.rb:146:in `run'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/application.rb:381:in `run'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/util.rb:496:in `exit_on_fail'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/application.rb:381:in `block in run'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/application.rb:507:in `plugin_hook'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/application.rb:381:in `block (2 levels) in run'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:159:in `run_command'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:198:in `main'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet.rb:246:in `override'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/context.rb:64:in `override'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:236:in `block in main'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:302:in `apply_catalog'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:133:in `run'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet.rb:246:in `override'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/context.rb:64:in `override'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:134:in `block in run'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:227:in `run_internal'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:119:in `apply_catalog'
2016-09-14 01:15:34 ERR /usr/lib/ruby/vendor_ruby/puppet/util.rb:160:in `benchmark'
2016-09-14 01:15:34 ERR /usr/lib/ruby/1.9.1/benchmark.r...

[M Lebel (mlebelj23all)]

Some of the logs seem to have disapeared..

I feel they are important and maybe contribute to the error. Here they are:

2016-09-14 01:15:31 NOTICE (Puppet::Type::Neutron_subnet::ProviderNeutron) SSL exception connecting to https://otcloud.makeitrain.omnitechcanada.net:9696/v2.0/subnets.json: [Errno 1] _ssl.c:510: error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed". Retrying for 1 sec.
2016-09-14 01:15:31 NOTICE (Puppet::Type::Neutron_subnet::ProviderNeutron) InsecurePlatformWarning
2016-09-14 01:15:31 NOTICE (Puppet::Type::Neutron_subnet::ProviderNeutron) /usr/lib/python2.7/dist-packages/urllib3/util/ssl_.py:120: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. For more information, see https://urllib3.readthedocs.org/en/latest/security.html#insecureplatformwarning.
2016-09-14 01:15:31 NOTICE (Puppet::Type::Neutron_subnet::ProviderNeutron) SNIMissingWarning
2016-09-14 01:15:31 NOTICE (Puppet::Type::Neutron_subnet::ProviderNeutron) Unable to complete neutron request due to non-fatal error: "Execution of '/usr/bin/neutron subnet-list --format=csv --column=id --quote=none' returned 1: /usr/lib/python2.7/dist-packages/urllib3/util/ssl_.py:315: SNIMissingWarning: An HTTPS request has been made, but the SNI (Subject Name Indication) extension to TLS is not available on this platform. This may cause the server to present an incorrect TLS certificate, which can cause validation failures. For more information, see https://urllib3.readthedocs.org/en/latest/security.html#snimissingwarning.
2016-09-14 01:15:28 NOTICE (Puppet::Type::Neutron_subnet::ProviderNeutron) SSL exception connecting to https://otcloud.makeitrain.omnitechcanada.net:9696/v2.0/subnets.json: [Errno 1] _ssl.c:510: error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed". Retrying for 4 sec.
2016-09-14 01:15:28 NOTICE (Puppet::Type::Neutron_subnet::ProviderNeutron) InsecurePlatformWarning

[M Lebel (mlebelj23all)]

Actual result:
Deploy Passed...

I finally got this working after I copied this file given to me by StartSSL called 1_root_bundle.crt over to all the nodes in the stack and installed them manually by running dpkg-reconfigure ca-certificates and manually adding this certificate.

This leaves me with one or two questions.
Is this an actual bug?
Or is this simply a wrong assumption on my part when I read from the Fuel UI:

"I have my own keypair with certificate
Use pre-generated key and certificate"
and
"Certificate and private key data, concatenated into a single file"

So my file contained cert key > pem file, maybe it should of been cert key ca_bundle > pem ?

thanks

[Maksim Malchuk (mmalchuk)]

Hi, and yes, this is known issue with certificates signed by an intermediate CA. We can't describe all possible cases on UI and I'm very glad that you solve the problem yourself.