Fuel for OpenStack

[OSTF] Keystone can not connect to mysql after nodes cold restart

Bug #1261332 reported by Tatyanka on 2013-12-16

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	Fuel for OpenStack	Invalid	Undecided	Vladimir Kuklin	Fuel for OpenStack 4.0

Bug Description

Rhel on KVM
Simple Falt
Scenario:
            1. Revert snapshot: deploy_simple_flat
            2. Turn off all nodes
            3. Start all nodes(wait while nodes become online in nailgun)
            4. Run OSTF

OSTF tests fail with:
keystoneclient.httpclient: DEBUG: Request returned failure status: 500
AuthorizationFailure: Authorization Failed: An unexpected error prevented the server from fulfilling your request. (OperationalError) (2003, "Can't connect to MySQL server on '127.0.0.1' (111)") None None (HTTP 500)

Logs in keystone.log
2013-12-16 01:04:51 INFO [access] 10.108.86.3 - - [16/Dec/2013:01:04:51 +0000] "POST http://10.108.86.3:5000/v2.0/tokens HTTP/1.0" 500 235
2013-12-16T01:05:53.145610+00:00 debug: 2013-12-16 01:04:51 DEBUG [eventlet.wsgi.server] 10.108.86.3 - - [16/Dec/2013 01:04:51] "POST /v2.0/tokens HTTP/1.1" 500 407 0.006291
2013-12-16T01:05:53.145610+00:00 debug: 2013-12-16 01:04:51 DEBUG [keystone.common.wsgi] arg_dict: {}
2013-12-16T01:05:53.145615+00:00 debug: 2013-12-16 01:04:51 ERROR [root] (OperationalError) (2003, "Can't connect to MySQL server on '127.0.0.1' (111)") None None
2013-12-16T01:05:53.145615+00:00 debug: Traceback (most recent call last):
2013-12-16T01:05:53.145619+00:00 debug: File "/usr/lib/python2.6/site-packages/keystone/common/wsgi.py", line 265, in __call__
2013-12-16T01:05:53.145619+00:00 debug: result = method(context, **params)
2013-12-16T01:05:53.145624+00:00 debug: File "/usr/lib/python2.6/site-packages/keystone/token/controllers.py", line 79, in authenticate
2013-12-16T01:05:53.145624+00:00 debug: context, auth)
2013-12-16T01:05:53.145630+00:00 debug: File "/usr/lib/python2.6/site-packages/keystone/token/controllers.py", line 289, in _authenticate_local
2013-12-16T01:05:53.145630+00:00 debug: domain_id=DEFAULT_DOMAIN_ID)
2013-12-16T01:05:53.145635+00:00 debug: File "/usr/lib/python2.6/site-packages/keystone/common/manager.py", line 47, in _wrapper
2013-12-16T01:05:53.145635+00:00 debug: return f(*args, **kw)
2013-12-16T01:05:53.145640+00:00 debug: File "/usr/lib/python2.6/site-packages/keystone/identity/backends/sql.py", line 655, in get_user_by_name
2013-12-16T01:05:53.145640+00:00 debug: self._get_user_by_name(user_name, domain_id))
2013-12-16T01:05:53.145646+00:00 debug: File "/usr/lib/python2.6/site-packages/keystone/identity/backends/sql.py", line 645, in _get_user_by_name
2013-12-16T01:05:53.145646+00:00 debug: user_ref = query.one()
2013-12-16T01:05:53.145649+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/query.py", line 2184, in one
2013-12-16T01:05:53.145649+00:00 debug: ret = list(self)
2013-12-16T01:05:53.145654+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/query.py", line 2227, in __iter__
2013-12-16T01:05:53.145654+00:00 debug: return self._execute_and_instances(context)
2013-12-16T01:05:53.145658+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/query.py", line 2240, in _execute_and_instances
2013-12-16T01:05:53.145658+00:00 debug: close_with_result=True)
2013-12-16T01:05:53.145663+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/query.py", line 2231, in _connection_from_session
2013-12-16T01:05:53.145663+00:00 debug: **kw)
2013-12-16T01:05:53.145670+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 730, in connection
2013-12-16T01:05:53.145670+00:00 debug: close_with_result=close_with_result)
2013-12-16T01:05:53.145677+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 736, in _connection_for_bind
2013-12-16T01:05:53.145677+00:00 debug: return engine.contextual_connect(**kwargs)
2013-12-16T01:05:53.145682+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 2490, in contextual_connect
2013-12-16T01:05:53.145682+00:00 debug: self.pool.connect(),
2013-12-16T01:05:53.145687+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/pool.py", line 224, in connect
2013-12-16T01:05:53.145687+00:00 debug: return _ConnectionFairy(self).checkout()
2013-12-16T01:05:53.145691+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/pool.py", line 387, in __init__
2013-12-16T01:05:53.145691+00:00 debug: rec = self._connection_record = pool._do_get()
2013-12-16T01:05:53.145695+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/pool.py", line 741, in _do_get
2013-12-16T01:05:53.145695+00:00 debug: con = self._create_connection()
2013-12-16T01:05:53.145700+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/pool.py", line 188, in _create_connection
2013-12-16T01:05:53.145700+00:00 debug: return _ConnectionRecord(self)
2013-12-16T01:05:53.145710+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/pool.py", line 270, in __init__
2013-12-16T01:05:53.145710+00:00 debug: self.connection = self.__connect()
2013-12-16T01:05:53.145715+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/pool.py", line 330, in __connect
2013-12-16T01:05:53.145715+00:00 debug: connection = self.__pool._creator()
2013-12-16T01:05:53.145719+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/engine/strategies.py", line 80, in connect
2013-12-16T01:05:53.145719+00:00 debug: return dialect.connect(*cargs, **cparams)
2013-12-16T01:05:53.145724+00:00 debug: File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/engine/default.py", line 281, in connect
2013-12-16T01:05:53.145724+00:00 debug: return self.dbapi.connect(*cargs, **cparams)
2013-12-16T01:05:53.145728+00:00 debug: File "/usr/lib64/python2.6/site-packages/MySQLdb/__init__.py", line 81, in Connect
2013-12-16T01:05:53.145728+00:00 debug: return Connection(*args, **kwargs)
2013-12-16T01:05:53.145733+00:00 debug: File "/usr/lib64/python2.6/site-packages/MySQLdb/connections.py", line 187, in __init__
2013-12-16T01:05:53.145733+00:00 debug: super(Connection, self).__init__(*args, **kwargs2)
2013-12-16T01:05:53.145741+00:00 debug: OperationalError: (OperationalError) (2003, "Can't connect to MySQL server on '127.0.0.1' (111)") None None
2013-12-16T01:05:53.145741+00:00 debug: 2013-12-16 01:04:51 INFO [access] 10.108.86.3 - - [16/Dec/2013:01:04:51 +0000] "POST http://10.108.86.3:5000/v2.0/tokens HTTP/1.0" 500 235