When mysql connection is broken (mysql server is restarted or virtual IP is moved around in typical HA setup), then keystone doesn't notice that connection was closed on the other side and first request after this outage fails. Because other openstack services autenticate incoming requests with keystone, the "first after-outage" request fails no matter what service is contacted.
I think the problem might be solved by catching DBConnectionError in sql backend and reconnecting to the mysql server before internal server error is returned to user. Alternatively it could be solved by adding heartbeat checks for mysql connection (which is probably more complex).
Example of failed request and server side error:
[tripleo@dell-per720xd-01 tripleo]$ keystone service-list
Authorization Failed: An unexpected error prevented the server from fulfilling your request. (HTTP 500)
Server log:
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 ERROR keystone.common.wsgi [-] (OperationalError) (2006, 'MySQL server has gone away') 'SELECT user.id AS user_id, user.name AS user_name, user.domain_id AS user_domain_id, user.password AS user_password, user.enabled AS user_enabled, user.extra AS user_extra, user.default_project_id AS user_default_project_id \nFROM user \nWHERE user.name = %s AND user.domain_id = %s' ('admin', 'default')
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi Traceback (most recent call last):
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/keystone/common/wsgi.py", line 223, in __call__
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi result = method(context, **params)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/keystone/token/controllers.py", line 100, in authenticate
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi context, auth)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/keystone/token/controllers.py", line 287, in _authenticate_local
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi username, CONF.identity.default_domain_id)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/keystone/identity/core.py", line 182, in wrapper
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi return f(self, *args, **kwargs)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/keystone/identity/core.py", line 193, in wrapper
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi return f(self, *args, **kwargs)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/keystone/identity/core.py", line 580, in get_user_by_name
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi ref = driver.get_user_by_name(user_name, domain_id)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/keystone/identity/backends/sql.py", line 140, in get_user_by_name
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi user_ref = query.one()
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2369, in one
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi ret = list(self)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2412, in __iter__
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi return self._execute_and_instances(context)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2427, in _execute_and_instances
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi result = conn.execute(querycontext.statement, self._params)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 729, in execute
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi return meth(self, multiparams, params)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 321, in _execute_on_connection
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi return connection._execute_clauseelement(self, multiparams, params)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi compiled_sql, distilled_params
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi context)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1156, in _handle_dbapi_exception
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi util.raise_from_cause(newraise, exc_info)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi reraise(type(exception), exception, tb=exc_tb)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi context)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 436, in do_execute
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi cursor.execute(statement, parameters)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/MySQLdb/cursors.py", line 205, in execute
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi self.errorhandler(self, exc, value)
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi raise errorclass, errorvalue
Sep 09 08:26:43 overcloud-controller0-rgy4hdcgqchc keystone-all[21782]: 2014-09-09 08:26:43.158 21782 TRACE keystone.common.wsgi DBConnectionError: (OperationalError) (2006, 'MySQL server has gone away') 'SELECT user.id AS user_id, user.name AS user_name, user.domain_id AS user_domain_id, user.password AS user_password, user.enabled AS user_enabled, user.extra AS user_extra, user.default_project_id AS user_default_project_id \nFROM user \nWHERE user.name = %s AND user.domain_id = %s' ('admin', 'default')
The second request ($ keystone service-list) works though, correct?