*** This bug is a duplicate of bug 1374497 ***
https://bugs.launchpad.net/bugs/1374497
** 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/1361378
Title:
"MySQL server has gone away" again
Status in OpenStack Identity (Keystone):
Invalid
Status in Oslo Database library:
Incomplete
Bug description:
This is a regression of an old issue, which I thought was resolved by
the "SELECT 1;" hack, but perhaps recently reintroduced with oslo.db?
[Mon Aug 25 14:30:54.403538 2014] [:error] [pid 25778:tid 139886259214080]
25778 ERROR keystone.common.wsgi [-] (OperationalError) (2003, "Can't connect
to MySQL server on '127.0.0.1' (111)") None None
[Mon Aug 25 14:30:54.403562 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi Traceback (most recent call last):
[Mon Aug 25 14:30:54.403570 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/common/wsgi.py", line 214, in __call__
[Mon Aug 25 14:30:54.403575 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi result = method(context, **params)
[Mon Aug 25 14:30:54.403581 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/token/controllers.py", line 99, in
authenticate
[Mon Aug 25 14:30:54.403589 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi context, auth)
[Mon Aug 25 14:30:54.403594 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/token/controllers.py", line 308, in
_authenticate_local
[Mon Aug 25 14:30:54.403600 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi username, CONF.identity.default_domain_id)
[Mon Aug 25 14:30:54.403606 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/identity/core.py", line 182, in wrapper
[Mon Aug 25 14:30:54.403612 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return f(self, *args, **kwargs)
[Mon Aug 25 14:30:54.403618 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/identity/core.py", line 193, in wrapper
[Mon Aug 25 14:30:54.403624 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return f(self, *args, **kwargs)
[Mon Aug 25 14:30:54.403630 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/identity/core.py", line 579, in
get_user_by_name
[Mon Aug 25 14:30:54.403637 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi ref = driver.get_user_by_name(user_name,
domain_id)
[Mon Aug 25 14:30:54.403644 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/identity/backends/sql.py", line 140, in
get_user_by_name
[Mon Aug 25 14:30:54.403650 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi user_ref = query.one()
[Mon Aug 25 14:30:54.403656 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2310, in one
[Mon Aug 25 14:30:54.403662 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi ret = list(self)
[Mon Aug 25 14:30:54.403667 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2353, in
__iter__
[Mon Aug 25 14:30:54.403673 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return self._execute_and_instances(context)
[Mon Aug 25 14:30:54.403680 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2366, in
_execute_and_instances
[Mon Aug 25 14:30:54.403731 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi close_with_result=True)
[Mon Aug 25 14:30:54.403740 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2357, in
_connection_from_session
[Mon Aug 25 14:30:54.403746 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi **kw)
[Mon Aug 25 14:30:54.403752 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 799, in
connection
[Mon Aug 25 14:30:54.403757 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi close_with_result=close_with_result)
[Mon Aug 25 14:30:54.403763 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 805, in
_connection_for_bind
[Mon Aug 25 14:30:54.403769 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return engine.contextual_connect(**kwargs)
[Mon Aug 25 14:30:54.403775 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1661, in
contextual_connect
[Mon Aug 25 14:30:54.403782 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi self.pool.connect(),
[Mon Aug 25 14:30:54.403787 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 272, in connect
[Mon Aug 25 14:30:54.403793 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return _ConnectionFairy(self).checkout()
[Mon Aug 25 14:30:54.403799 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 431, in __init__
[Mon Aug 25 14:30:54.403804 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi rec = self._connection_record =
pool._do_get()
[Mon Aug 25 14:30:54.403810 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 772, in _do_get
[Mon Aug 25 14:30:54.403815 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return self._create_connection()
[Mon Aug 25 14:30:54.403820 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 225, in
_create_connection
[Mon Aug 25 14:30:54.403826 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return _ConnectionRecord(self)
[Mon Aug 25 14:30:54.403833 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 318, in __init__
[Mon Aug 25 14:30:54.403839 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi self.connection = self.__connect()
[Mon Aug 25 14:30:54.403845 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 379, in __connect
[Mon Aug 25 14:30:54.403851 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi connection = self.__pool._creator()
[Mon Aug 25 14:30:54.403857 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/engine/strategies.py", line 80, in
connect
[Mon Aug 25 14:30:54.403862 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return dialect.connect(*cargs, **cparams)
[Mon Aug 25 14:30:54.403868 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 283, in
connect
[Mon Aug 25 14:30:54.403888 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return self.dbapi.connect(*cargs,
**cparams)
[Mon Aug 25 14:30:54.403894 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/MySQLdb/__init__.py", line 81, in Connect
[Mon Aug 25 14:30:54.403901 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi return Connection(*args, **kwargs)
[Mon Aug 25 14:30:54.403906 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 187, in __init__
[Mon Aug 25 14:30:54.403911 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi super(Connection, self).__init__(*args,
**kwargs2)
[Mon Aug 25 14:30:54.403918 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi OperationalError: (OperationalError) (2003,
"Can't connect to MySQL server on '127.0.0.1' (111)") None None
[Mon Aug 25 14:30:54.403924 2014] [:error] [pid 25778:tid 139886259214080]
25778 TRACE keystone.common.wsgi
[Mon Aug 25 14:30:54.425356 2014] [authz_core:debug] [pid 25788:tid
139886145304320] mod_authz_core.c(802): [client 127.0.0.1:46458] AH01626:
authorization result of Require all granted: granted
[Mon Aug 25 14:30:54.425387 2014] [authz_core:debug] [pid 25788:tid
139886145304320] mod_authz_core.c(802): [client 127.0.0.1:46458] AH01626:
authorization result of : granted
[Mon Aug 25 14:30:54.425432 2014] [authz_core:debug] [pid 25788:tid
139886145304320] mod_authz_core.c(802): [client 127.0.0.1:46458] AH01626:
authorization result of Require all granted: granted
[Mon Aug 25 14:30:54.425446 2014] [authz_core:debug] [pid 25788:tid
139886145304320] mod_authz_core.c(802): [client 127.0.0.1:46458] AH01626:
authorization result of : granted
[Mon Aug 25 14:30:54.426830 2014] [:error] [pid 25779:tid 139886259214080]
25779 DEBUG keystone.middleware.core [-] Auth token not in the request header.
Will not build auth context. process_request
/opt/stack/new/keystone/keystone/middleware/core.py:276
[Mon Aug 25 14:30:54.428226 2014] [:error] [pid 25779:tid 139886259214080]
25779 DEBUG keystone.common.wsgi [-] arg_dict: {} __call__
/opt/stack/new/keystone/keystone/common/wsgi.py:183
[Mon Aug 25 14:30:54.432009 2014] [:error] [pid 25779:tid 139886259214080]
25779 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' ('demo', 'default')
[Mon Aug 25 14:30:54.432034 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi Traceback (most recent call last):
[Mon Aug 25 14:30:54.432041 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/common/wsgi.py", line 214, in __call__
[Mon Aug 25 14:30:54.432047 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi result = method(context, **params)
[Mon Aug 25 14:30:54.432053 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/token/controllers.py", line 99, in
authenticate
[Mon Aug 25 14:30:54.432059 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi context, auth)
[Mon Aug 25 14:30:54.432065 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/token/controllers.py", line 308, in
_authenticate_local
[Mon Aug 25 14:30:54.432071 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi username, CONF.identity.default_domain_id)
[Mon Aug 25 14:30:54.432091 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/identity/core.py", line 182, in wrapper
[Mon Aug 25 14:30:54.432097 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi return f(self, *args, **kwargs)
[Mon Aug 25 14:30:54.432103 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/identity/core.py", line 193, in wrapper
[Mon Aug 25 14:30:54.432108 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi return f(self, *args, **kwargs)
[Mon Aug 25 14:30:54.432114 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/identity/core.py", line 579, in
get_user_by_name
[Mon Aug 25 14:30:54.432121 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi ref = driver.get_user_by_name(user_name,
domain_id)
[Mon Aug 25 14:30:54.432128 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/opt/stack/new/keystone/keystone/identity/backends/sql.py", line 140, in
get_user_by_name
[Mon Aug 25 14:30:54.432135 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi user_ref = query.one()
[Mon Aug 25 14:30:54.432140 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2310, in one
[Mon Aug 25 14:30:54.432146 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi ret = list(self)
[Mon Aug 25 14:30:54.432154 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2353, in
__iter__
[Mon Aug 25 14:30:54.432160 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi return self._execute_and_instances(context)
[Mon Aug 25 14:30:54.432169 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2368, in
_execute_and_instances
[Mon Aug 25 14:30:54.432174 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi result =
conn.execute(querycontext.statement, self._params)
[Mon Aug 25 14:30:54.432180 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in
execute
[Mon Aug 25 14:30:54.432186 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi params)
[Mon Aug 25 14:30:54.432191 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in
_execute_clauseelement
[Mon Aug 25 14:30:54.432197 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi compiled_sql, distilled_params
[Mon Aug 25 14:30:54.432203 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in
_execute_context
[Mon Aug 25 14:30:54.432209 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi context)
[Mon Aug 25 14:30:54.432217 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/local/lib/python2.7/dist-packages/oslo/db/sqlalchemy/compat/handle_error.py",
line 125, in _handle_dbapi_exception
[Mon Aug 25 14:30:54.432223 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi six.reraise(type(newraise), newraise,
sys.exc_info()[2])
[Mon Aug 25 14:30:54.432232 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/local/lib/python2.7/dist-packages/oslo/db/sqlalchemy/compat/handle_error.py",
line 102, in _handle_dbapi_exception
[Mon Aug 25 14:30:54.432250 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi per_fn = fn(ctx)
[Mon Aug 25 14:30:54.432256 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/local/lib/python2.7/dist-packages/oslo/db/sqlalchemy/exc_filters.py",
line 323, in handler
[Mon Aug 25 14:30:54.432263 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi context.is_disconnect)
[Mon Aug 25 14:30:54.432270 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi File
"/usr/local/lib/python2.7/dist-packages/oslo/db/sqlalchemy/exc_filters.py",
line 263, in _is_db_connection_error
[Mon Aug 25 14:30:54.432277 2014] [:error] [pid 25779:tid 139886259214080]
25779 TRACE keystone.common.wsgi raise
exception.DBConnectionError(operational_error)
[Mon Aug 25 14:30:54.432286 2014] [:error] [pid 25779:tid 139886259214080]
25779 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' ('demo', 'default')
This appeared as a transient issue in
http://logs.openstack.org/74/111574/4/gate/gate-tempest-dsvm-neutron-
full/a8ff79a/logs/screen-key.txt.gz
To manage notifications about this bug go to:
https://bugs.launchpad.net/keystone/+bug/1361378/+subscriptions
--
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to : [email protected]
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help : https://help.launchpad.net/ListHelp