yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1367218] Re: Broken mysql connection causes internal server error

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Roman Podoliaka <rpodolyaka+bugs@xxxxxxxxxxxx>
Date: Mon, 24 Nov 2014 09:32:33 -0000
Reply-to: Bug 1367218 <1367218@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
*** This bug is a duplicate of bug 1374497 ***
    https://bugs.launchpad.net/bugs/1374497

** This bug is no longer a duplicate of bug 1361378
   "MySQL server has gone away" again
** This bug has been marked a duplicate of bug 1374497
   change in oslo.db "ping" handling is causing issues in projects that are not using transactions

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to Keystone.
https://bugs.launchpad.net/bugs/1367218

Title:
  Broken mysql connection causes internal server error

Status in OpenStack Identity (Keystone):
  Confirmed

Bug description:
  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')

To manage notifications about this bug go to:
https://bugs.launchpad.net/keystone/+bug/1367218/+subscriptions
References

[Bug 1367218] [NEW] Broken mysql connection causes internal server errorr
From: Jan Provaznik, 2014-09-09