[FUEL] Controller deployment failed

[Viktoria Efimova]

Bug occured during deployment with using custom centos repo http://osci-obs.vm.mirantis.net:82/centos-fuel-6.1-stable-7715/centos due https://bugs.launchpad.net/mos/6.1.x/+bug/1459781

During deployment on controller puppet reports about fauilure to connect to local MySQL server:

2015-06-11 00:53:10 ERR
 /usr/bin/puppet:4
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/util/command_line.rb:91:in `execute'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/util/command_line.rb:137:in `run'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:364:in `run'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:478:in `exit_on_fail'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:364:in `run'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:470:in `plugin_hook'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/application.rb:364:in `run'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/application/apply.rb:146:in `run_command'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/application/apply.rb:218:in `main'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/application/apply.rb:268:in `apply_catalog'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/configurer.rb:192:in `run'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/configurer.rb:124:in `apply_catalog'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:160:in `benchmark'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/1.8/benchmark.rb:308:in `realtime'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:161:in `benchmark'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/configurer.rb:125:in `apply_catalog'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/resource/catalog.rb:163:in `apply'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction/report.rb:108:in `as_logging_destination'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/util/log.rb:149:in `with_destination'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/resource/catalog.rb:164:in `apply'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:108:in `evaluate'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/graph/relationship_graph.rb:118:in `traverse'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:117:in `evaluate'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:326:in `thinmark'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/1.8/benchmark.rb:308:in `realtime'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/util.rb:327:in `thinmark'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:117:in `evaluate'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:117:in `call'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:187:in `eval_resource'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction.rb:174:in `apply'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction/resource_harness.rb:18:in `evaluate'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction/resource_harness.rb:81:in `perform_changes'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction/resource_harness.rb:81:in `each'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction/resource_harness.rb:82:in `perform_changes'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction/resource_harness.rb:130:in `sync_if_needed'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/transaction/resource_harness.rb:193:in `sync'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/type/exec.rb:120:in `sync'
2015-06-11 00:53:10 ERR
 /usr/lib/ruby/site_ruby/1.8/puppet/util/errors.rb:97:in `fail'
2015-06-11 00:53:10 ERR
 /usr/bin/mysql -uwsrep_sst -pNe7JIBkm -Nbe "show status like 'wsrep_local_state_comment'" | /bin/grep -q Synced && sleep 10 returned 1 instead of one of [0]
2015-06-11 00:53:10 NOTICE
 (/Stage[main]/Galera/Exec[wait-for-synced-state]/returns) ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2)
2015-06-11 00:53:10 NOTICE
 (/Stage[main]/Galera/Exec[wait-for-synced-state]/returns) Warning: Using a password on the command line interface can be insecure.

Deployment details:
Centos,IBP,HA, Neutron-gre,Ceph-all,Nova-debug,Nova-quotas, 6.1-521 Controllers:3 Computes:47

Log snapshot can be downloaded at http://mos-scale-share.mirantis.com/fuel-snapshot-2015-06-11_09-54-13.tar.xz

[Oleksiy Molchanov (omolchanov)]

Mysql was Synced when I access the failed node on that env. After investigation I found out, that the problem was related to connectivity between donor node-1 and failed node-3. Node-3 was opening 4444 port on mgmt ip using socat and Node-1 was trying to connect to it, but each time was failing with "Connection timed out" error. It is very strange, because they were communicating with each other in order to establish SST.

I didn't manage to find anything in logs that is related to some problems with opening 4444 port. As I told mysql was synced 3 hours before I accessed the env, so I couldn't diagnose the root cause. Also I was reported that nobody was working there.

I am marking it as incomplete, because it is impossible to reproduce.

[Nastya Urlapova (aurlapova)]

Please, leave an env if issue will reproduce again.